-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1

Matthew Edlefsen wrote:

Hi, I've been trying to use syncrepl to replicate my cn=config tree and have been running into some issues. After running into a number of things not working I completely stripped everything down and attempted to follow test049 by building it from scratch. I've gotten it to work by running two instances of slapd on the same machine, on both machines, but I still can't get it to work between the two machines.

System info Provider: FreeBSD 7.1-PRERELEASE FreeBSD 7.1-PRERELEASE #0: Sat Nov 15 18:38:32 EST 2008 OpenLDAP 2.4.16

Consumer: FreeBSD 7.2-STABLE FreeBSD 7.2-STABLE #1: Mon Jun 1 12:29:14 EDT 2009 OpenLDAP 2.4.16

My process is this: First I create slapd.d directories for both servers and populate them with a basic config

mkdir slapd.d

slapadd -n 0 -F slapd.d <<END dn: cn=config objectClass: olcGlobal cn: config olcLogLevel: Trace olcLogLevel: Config olcLogLevel: Stats olcLogLevel: Sync olcLogLevel: Args olcLogLevel: Conns

dn: olcDatabase={0}config,cn=config objectClass: olcDatabaseConfig olcRootDN: $MANAGER olcRootPW: $CONFIGPW olcDatabase: {0}config

dn: olcOverlay=syncprov,olcDatabase={0}config,cn=config objectClass: olcOverlayConfig objectClass: olcSyncProvConfig olcOverlay: syncprov END

chown -R ldap:ldap slapd.d

Then I launch slapd with:

/usr/local/libexec/slapd -h $URI -u ldap -g ldap

on both machines.

At this point I can do ldapsearch on both servers and get back the correct results. I then do:

ldapmodify -D "$MANAGER" -x -w "$CONFIGPW" <<END dn: olcDatabase={0}config,cn=config changetype: modify add: olcSyncRepl olcSyncRepl: rid=001 provider=$PROVIDER_URI binddn="$MANAGER" bindmethod=simple credentials=$CONFIGPW searchbase="cn=config" type=refreshAndPersist retry="3 5 300 5" timeout=3

add: olcUpdateRef olcUpdateRef: $PROVIDER_URI END

At this point I start logging the same error over and over. Here are the log messages I get:

Consumer: Jun 3 19:55:35 jet slapd[51003]: =>do_syncrepl rid=001 Jun 3 19:55:35 jet slapd[51003]: =>do_syncrep2 rid=001 Jun 3 19:55:35 jet slapd[51003]: connection_get(7) Jun 3 19:55:35 jet slapd[51003]: connection_get(7): got connid=0 Jun 3 19:55:35 jet slapd[51003]: =>do_syncrepl rid=001 Jun 3 19:55:35 jet slapd[51003]: =>do_syncrep2 rid=001 Jun 3 19:55:35 jet slapd[51003]: >>> dnPrettyNormal: <cn=config> Jun 3 19:55:35 jet slapd[51003]: <<< dnPrettyNormal: <cn=config>, <cn=config> Jun 3 19:55:35 jet slapd[51003]: >>> dnPretty: <cn=config> Jun 3 19:55:35 jet slapd[51003]: <<< dnPretty: <cn=config> Jun 3 19:55:35 jet slapd[51003]: >>> dnNormalize: <cn=config> Jun 3 19:55:35 jet slapd[51003]: <<< dnNormalize: <cn=config> Jun 3 19:55:35 jet slapd[51003]: >>> dnPretty: <cn=config> Jun 3 19:55:35 jet slapd[51003]: <<< dnPretty: <cn=config> Jun 3 19:55:35 jet slapd[51003]: >>> dnNormalize: <cn=config> Jun 3 19:55:35 jet slapd[51003]: <<< dnNormalize: <cn=config> Jun 3 19:55:35 jet slapd[51003]: >>> dnPretty: <cn=config> Jun 3 19:55:35 jet slapd[51003]: <<< dnPretty: <cn=config> Jun 3 19:55:35 jet slapd[51003]: >>> dnNormalize: <cn=config> Jun 3 19:55:35 jet slapd[51003]: <<< dnNormalize: <cn=config> Jun 3 19:55:35 jet slapd[51003]: >>> dnPretty: <cn=Subschema> Jun 3 19:55:35 jet slapd[51003]: <<< dnPretty: <cn=Subschema> Jun 3 19:55:35 jet slapd[51003]: >>> dnNormalize: <cn=Subschema> Jun 3 19:55:35 jet slapd[51003]: <<< dnNormalize: <cn=subschema> Jun 3 19:55:35 jet slapd[51003]: syncrepl_entry: rid=001 LDAP_RES_SEARCH_ENTRY(LDAP_SYNC_ADD) Jun 3 19:55:35 jet slapd[51003]: dn_callback : entries have identical CSN cn=config 20090603203325.264042Z#000000#000#000000 Jun 3 19:55:35 jet slapd[51003]: send_ldap_result: conn=-1 op=0 p=0 Jun 3 19:55:35 jet slapd[51003]: send_ldap_result: err=0 matched="" text="" Jun 3 19:55:35 jet slapd[51003]: syncrepl_entry: rid=001 be_search (0) Jun 3 19:55:35 jet slapd[51003]: syncrepl_entry: rid=001 cn=config Jun 3 19:55:35 jet slapd[51003]: syncrepl_entry: rid=001 entry unchanged, ignored (cn=config) Jun 3 19:55:35 jet slapd[51003]: connection_get(7) Jun 3 19:55:35 jet slapd[51003]: connection_get(7): got connid=0 Jun 3 19:55:35 jet slapd[51003]: =>do_syncrepl rid=001 Jun 3 19:55:35 jet slapd[51003]: =>do_syncrep2 rid=001 Jun 3 19:55:35 jet slapd[51003]: connection_get(7) Jun 3 19:55:35 jet slapd[51003]: connection_get(7): got connid=0 Jun 3 19:55:35 jet slapd[51003]: =>do_syncrepl rid=001 Jun 3 19:55:35 jet slapd[51003]: =>do_syncrep2 rid=001 Jun 3 19:55:35 jet slapd[51003]: connection_get(7) Jun 3 19:55:35 jet slapd[51003]: connection_get(7): got connid=0 Jun 3 19:55:35 jet slapd[51003]: =>do_syncrepl rid=001 Jun 3 19:55:35 jet slapd[51003]: =>do_syncrep2 rid=001 Jun 3 19:55:35 jet slapd[51003]: >>> dnPrettyNormal: <cn=schema,cn=config> Jun 3 19:55:35 jet slapd[51003]: <<< dnPrettyNormal: <cn=schema,cn=config>, <cn=schema,cn=config> Jun 3 19:55:35 jet slapd[51003]: >>> dnPretty: <cn=config> Jun 3 19:55:35 jet slapd[51003]: <<< dnPretty: <cn=config> Jun 3 19:55:35 jet slapd[51003]: >>> dnNormalize: <cn=config> Jun 3 19:55:35 jet slapd[51003]: <<< dnNormalize: <cn=config> Jun 3 19:55:35 jet slapd[51003]: >>> dnPretty: <cn=config> Jun 3 19:55:35 jet slapd[51003]: <<< dnPretty: <cn=config> Jun 3 19:55:35 jet slapd[51003]: >>> dnNormalize: <cn=config> Jun 3 19:55:35 jet slapd[51003]: <<< dnNormalize: <cn=config> Jun 3 19:55:35 jet slapd[51003]: >>> dnPretty: <cn=schema,cn=config> Jun 3 19:55:35 jet slapd[51003]: <<< dnPretty: <cn=schema,cn=config> Jun 3 19:55:35 jet slapd[51003]: >>> dnNormalize: <cn=schema,cn=config> Jun 3 19:55:35 jet slapd[51003]: <<< dnNormalize: <cn=schema,cn=config> Jun 3 19:55:35 jet slapd[51003]: >>> dnPretty: <cn=Subschema> Jun 3 19:55:35 jet slapd[51003]: <<< dnPretty: <cn=Subschema> Jun 3 19:55:35 jet slapd[51003]: >>> dnNormalize: <cn=Subschema> Jun 3 19:55:35 jet slapd[51003]: <<< dnNormalize: <cn=subschema> Jun 3 19:55:35 jet slapd[51003]: syncrepl_entry: rid=001 LDAP_RES_SEARCH_ENTRY(LDAP_SYNC_ADD) Jun 3 19:55:35 jet slapd[51003]: send_ldap_result: conn=-1 op=0 p=0 Jun 3 19:55:35 jet slapd[51003]: send_ldap_result: err=0 matched="" text="" Jun 3 19:55:35 jet slapd[51003]: syncrepl_entry: rid=001 be_search (0) Jun 3 19:55:35 jet slapd[51003]: syncrepl_entry: rid=001 cn=schema,cn=config Jun 3 19:55:35 jet slapd[51003]: conn=-1 op=0: config_add_internal: DN="cn=schema,cn=config" already exists Jun 3 19:55:35 jet slapd[51003]: send_ldap_result: conn=-1 op=0 p=0 Jun 3 19:55:35 jet slapd[51003]: send_ldap_result: err=68 matched="" text="" Jun 3 19:55:35 jet slapd[51003]: syncrepl_entry: rid=001 be_add cn=schema,cn=config (68) Jun 3 19:55:35 jet slapd[51003]: send_ldap_result: conn=-1 op=0 p=0 Jun 3 19:55:35 jet slapd[51003]: send_ldap_result: err=0 matched="" text="" Jun 3 19:55:35 jet slapd[51003]: send_ldap_result: conn=-1 op=0 p=0 Jun 3 19:55:35 jet slapd[51003]: send_ldap_result: err=1 matched="" text="" Jun 3 19:55:35 jet slapd[51003]: null_callback : error code 0x1 Jun 3 19:55:35 jet slapd[51003]: syncrepl_entry: rid=001 be_modify cn=schema,cn=config (1) Jun 3 19:55:35 jet slapd[51003]: syncrepl_entry: rid=001 be_modify failed (1) Jun 3 19:55:35 jet slapd[51003]: connection_get(7) Jun 3 19:55:35 jet slapd[51003]: connection_get(7): got connid=0 Jun 3 19:55:35 jet slapd[51003]: do_syncrepl: rid=001 rc 1 retrying (4 retries left)

Provider: Jun 3 17:02:36 rock slapd[75268]: slap_listener_activate(6): Jun 3 17:02:36 rock slapd[75268]: >>> slap_listener($PROV_URI) Jun 3 17:02:36 rock slapd[75268]: conn=391 fd=8 ACCEPT from IP=$CONS_IP:56003 (IP=$PROV_IP:389) Jun 3 17:02:36 rock slapd[75268]: connection_get(8): got connid=391 Jun 3 17:02:36 rock slapd[75268]: connection_read(8): checking for input on id=391 Jun 3 17:02:36 rock slapd[75268]: conn=391 op=0 do_bind Jun 3 17:02:36 rock slapd[75268]: >>> dnPrettyNormal: <cn=manager,cn=config> Jun 3 17:02:36 rock slapd[75268]: <<< dnPrettyNormal: <cn=manager,cn=config>, <cn=manager,cn=config> Jun 3 17:02:36 rock slapd[75268]: conn=391 op=0 BIND dn="cn=manager,cn=config" method=128 Jun 3 17:02:36 rock slapd[75268]: do_bind: version=3 dn="cn=manager,cn=config" method=128 Jun 3 17:02:36 rock slapd[75268]: conn=391 op=0 BIND dn="cn=manager,cn=config" mech=SIMPLE ssf=0 Jun 3 17:02:36 rock slapd[75268]: do_bind: v3 bind: "cn=manager,cn=config" to "cn=manager,cn=config" Jun 3 17:02:36 rock slapd[75268]: send_ldap_result: conn=391 op=0 p=3 Jun 3 17:02:36 rock slapd[75268]: send_ldap_response: msgid=1 tag=97 err=0 Jun 3 17:02:36 rock slapd[75268]: conn=391 op=0 RESULT tag=97 err=0 text= Jun 3 17:02:36 rock slapd[75268]: connection_get(8): got connid=391 Jun 3 17:02:36 rock slapd[75268]: connection_read(8): checking for input on id=391 Jun 3 17:02:36 rock slapd[75268]: conn=391 op=1 do_search Jun 3 17:02:36 rock slapd[75268]: >>> dnPrettyNormal: <cn=config> Jun 3 17:02:36 rock slapd[75268]: <<< dnPrettyNormal: <cn=config>, <cn=config> Jun 3 17:02:36 rock slapd[75268]: => get_ctrls Jun 3 17:02:36 rock slapd[75268]: => get_ctrls: oid="1.3.6.1.4.1.4203.1.9.1.1" (noncritical) Jun 3 17:02:36 rock slapd[75268]: => get_ctrls: oid="2.16.840.1.113730.3.4.2" (critical) Jun 3 17:02:36 rock slapd[75268]: <= get_ctrls: n=2 rc=0 err="" Jun 3 17:02:36 rock slapd[75268]: conn=391 op=1 SRCH base="cn=config" scope=2 deref=0 filter="(objectClass=*)" Jun 3 17:02:36 rock slapd[75268]: conn=391 op=1 SRCH attr=* + Jun 3 17:02:36 rock slapd[75268]: send_ldap_result: conn=391 op=1 p=3 Jun 3 17:02:36 rock last message repeated 2 times Jun 3 17:02:36 rock slapd[75268]: => send_search_entry: conn 391 dn="cn=config" Jun 3 17:02:36 rock slapd[75268]: <= send_search_entry: conn 391 exit. Jun 3 17:02:36 rock slapd[75268]: => send_search_entry: conn 391 dn="cn=schema,cn=config" Jun 3 17:02:36 rock slapd[75268]: connection_get(8): got connid=391 Jun 3 17:02:36 rock slapd[75268]: connection_write(8): waking output for id=391 Jun 3 17:02:36 rock slapd[75268]: <= send_search_entry: conn 391 exit. Jun 3 17:02:36 rock slapd[75268]: => send_search_entry: conn 391 dn="cn={0}core,cn=schema,cn=config" Jun 3 17:02:36 rock slapd[75268]: connection_get(8): got connid=391 Jun 3 17:02:36 rock slapd[75268]: connection_write(8): waking output for id=391 Jun 3 17:02:36 rock slapd[75268]: <= send_search_entry: conn 391 exit. Jun 3 17:02:36 rock slapd[75268]: => send_search_entry: conn 391 dn="cn={1}cosine,cn=schema,cn=config" Jun 3 17:02:36 rock slapd[75268]: connection_get(8): got connid=391 Jun 3 17:02:36 rock slapd[75268]: connection_write(8): waking output for id=391 Jun 3 17:02:36 rock slapd[75268]: <= send_search_entry: conn 391 exit. Jun 3 17:02:36 rock slapd[75268]: => send_search_entry: conn 391 dn="cn={2}inetorgperson,cn=schema,cn=config" Jun 3 17:02:36 rock slapd[75268]: <= send_search_entry: conn 391 exit. Jun 3 17:02:36 rock slapd[75268]: => send_search_entry: conn 391 dn="cn={3}nis,cn=schema,cn=config" Jun 3 17:02:36 rock slapd[75268]: <= send_search_entry: conn 391 exit. Jun 3 17:02:36 rock slapd[75268]: => send_search_entry: conn 391 dn="olcDatabase={-1}frontend,cn=config" Jun 3 17:02:36 rock slapd[75268]: <= send_search_entry: conn 391 exit. Jun 3 17:02:36 rock slapd[75268]: => send_search_entry: conn 391 dn="olcDatabase={0}config,cn=config" Jun 3 17:02:36 rock slapd[75/: <= send_search_entry: conn 391 exit. Jun 3 17:02:36 rock slapd[75268]: => send_search_entry: conn 391 dn="olcOverlay={0}syncprov,olcDatabase={0}config,cn=config" Jun 3 17:02:36 rock slapd[75268]: <= send_search_entry: conn 391 exit. Jun 3 17:02:36 rock slapd[75268]: send_ldap_result: conn=391 op=1 p=3 Jun 3 17:02:36 rock slapd[75268]: send_ldap_intermediate: err=0 oid=1.3.6.1.4.1.4203.1.9.1.4 len=56 Jun 3 17:02:36 rock slapd[75268]: send_ldap_response: msgid=2 tag=121 err=0 Jun 3 17:02:36 rock slapd[75268]: connection_get(8): got connid=391 Jun 3 17:02:36 rock slapd[75268]: connection_read(8): checking for input on id=391 Jun 3 17:02:36 rock slapd[75268]: ber_get_next on fd 8 failed errno=0 (Undefined error: 0) Jun 3 17:02:36 rock slapd[75268]: conn=391 op=2 do_unbind Jun 3 17:02:36 rock slapd[75268]: conn=391 op=2 UNBIND Jun 3 17:02:36 rock slapd[75268]: connection_close: conn=391 sd=8 Jun 3 17:02:36 rock slapd[75268]: conn=391 fd=8 closed

As I said it works perfectly if it's two slapd instances on the same machine on different ports. The machines can talk to each other and can both ldapsearch the other one. Also the firewall is reporting no blocks.

If anybody has seen this before or has some insight into what the problem might be it would be very much apprectiated.

Thank you in advance, Matt Edlefsen Earlham College

How are you populating cn=config on each machine? Freshly or import first one, export from that and then import into other machine so they have the correct *CSN values?

When on the same machine are you pointing both slapd to the same config but just starting on different ports?

- -- Kind Regards,

Gavin Henry. Managing Director.

T +44 (0) 1224 279484 M +44 (0) 7930 323266 F +44 (0) 1224 824887 E ghenry@suretecsystems.com

Open Source. Open Solutions(tm).

http://www.suretecsystems.com/

Suretec Systems is a limited company registered in Scotland. Registered number: SC258005. Registered office: 13 Whiteley Well Place, Inverurie, Aberdeenshire, AB51 4FP.

Subject to disclaimer at http://www.suretecgroup.com/disclaimer.html