[Date Prev][Date Next] [Chronological] [Thread] [Top]

syncrepl consumer retry and sync questions

Hi,
Concluding from the documentation (I think it's not clear on this), retry="60 +" should mean that the consumer retries indefinitely every 60 seconds. 

However, I am observing that consumers with the config:

   syncrepl rid=111
            provider=ldaps://ldap.example.com
            tls_reqcert=never
            type=refreshAndPersist
            retry="60 +"
            searchbase="dc=example,dc=com"
            schemachecking=off
            bindmethod=simple
            binddn="cn=Manager,dc=example,dc=com"
            credentials="secret"

retry the first time after 60 seconds, then retry again after 2 hours:
(Note: Consumers lose connection to the provider at 18:47:59 as the provider is stopped for a few minutes to become upgraded to 2.4.pre30.)
Feb 25 18:47:59 consumer111 slapd[2482]: do_syncrep2: rid=111 (-1) Can't contact LDAP server 
Feb 25 18:47:59 consumer111 slapd[2482]: do_syncrepl: rid=111 rc -1 retrying
Feb 25 18:48:59 consumer111 slapd[2482]: do_syncrep2: rid=111 LDAP_RES_INTERMEDIATE - REFRESH_DELETE Feb 25 20:48:59 consumer111 slapd[2482]: do_syncrep2: rid=111 (-1) Can't contact LDAP server 
Feb 25 20:48:59 consumer111 slapd[2482]: do_syncrepl: rid=111 rc -1 retrying
Feb 25 20:48:59 consumer111 slapd[2482]: connection_read(35): no connection!
Feb 25 20:48:59 consumer111 slapd[2482]: connection_read(35): no connection!
Feb 25 20:49:59 consumer111 slapd[2482]: syncrepl_entry: rid=111 LDAP_RES_SEARCH_ENTRY(LDAP_SYNC_ADD) 
...sync continues...
Note that there were a bunch of edits on the provider between 19:47 and 19:55 but they were not propagated to this consumer, until 20:49.
About my other two consumers (which have identical configuration, but they bind with a non-root user), on which I wrote on my earlier email: It seems they were also in some kind of delay (for two hours too??), but I didn't wait and restarted slapd: 

The first:
Feb 25 18:47:59 consumer222 slapd2.4[2140]: do_syncrep2: rid=222 (-1) Can't contact LDAP server Feb 25 18:47:59 consumer222 slapd2.4[2140]: do_syncrepl: rid=222 rc -1 retrying Feb 25 18:48:59 consumer222 slapd2.4[2140]: do_syncrep2: rid=222 LDAP_RES_INTERMEDIATE - REFRESH_DELETE 
Feb 25 20:18:04 consumer222 slapd2.4[2141]: slapd starting
Feb 25 20:18:04 consumer222 slapd2.4[2141]: syncrepl_entry: rid=222 LDAP_RES_SEARCH_ENTRY(LDAP_SYNC_ADD) 
...sync continues...

and the second:
This one was stopped and upgraded to 2.4.30b3 (as I named it - it was pre-30): At 18:54:45 (and later at 19:29) it was started after upgrade, then, as it was not syncing, it was restarted at 20:02:55 and it synced.
Feb 25 18:47:59 consumer333 slapd[2357]: do_syncrep2: rid=333 (-1) Can't contact LDAP server 
Feb 25 18:47:59 consumer333 slapd[2357]: do_syncrepl: rid=333 rc -1 retrying
Feb 25 18:48:59 consumer333 slapd[2357]: do_syncrep2: rid=333 LDAP_RES_INTERMEDIATE - REFRESH_DELETE Feb 25 18:52:39 consumer333 slapd[2357]: daemon: shutdown requested and initiated. Feb 25 18:52:39 consumer333 slapd[2357]: slapd shutdown: waiting for 1 operations/tasks to finish 
Feb 25 18:52:40 consumer333 slapd[2357]: slapd stopped.
Feb 25 18:52:40 consumer333 slapd[23371]: [OK] OpenLDAP stopped after 1 seconds 
Feb 25 18:52:40 consumer333 slapd[23372]: [INFO] no data backup done
Feb 25 18:52:40 consumer333 slapd[23373]: [INFO] Halting OpenLDAP replication... Feb 25 18:52:40 consumer333 slapd[23374]: [INFO] no replica found in configuration, aborting stopping slurpd Feb 25 18:54:27 consumer333 slapd[23425]: [INFO] Using /etc/default/slapd for configuration 
Feb 25 18:54:27 consumer333 slapd[23430]: [INFO] Halting OpenLDAP...
Feb 25 18:54:27 consumer333 slapd[23431]: [INFO] can't read PID file, to stop slapd try: /etc/init.d/slapd forcestop Feb 25 18:54:27 consumer333 slapd[23432]: [INFO] Halting OpenLDAP replication... Feb 25 18:54:27 consumer333 slapd[23433]: [INFO] no replica found in configuration, aborting stopping slurpd Feb 25 18:54:44 consumer333 slapd[23458]: [INFO] Using /etc/default/slapd for configuration Feb 25 18:54:44 consumer333 slapd[23463]: [INFO] Launching OpenLDAP configuration test... Feb 25 18:54:45 consumer333 slapd[23486]: [OK] OpenLDAP configuration test successful 
Feb 25 18:54:45 consumer333 slapd[23496]: [INFO] No db_recover done
Feb 25 18:54:45 consumer333 slapd[23497]: [INFO] Launching OpenLDAP...
Feb 25 18:54:45 consumer333 slapd[23498]: [OK] File descriptor limit set to 1024 Feb 25 18:54:45 consumer333 slapd[23499]: @(#) $OpenLDAP: slapd 2.4.X (Feb 25 2012 18:38:31) $ swbuilder@vdev.example.com:/home/swbuilder/rpmbuild/BUILD/openldap-2.4.30b3/servers/slapd 
Feb 25 18:54:45 consumer333 slapd[23500]: slapd starting
Feb 25 18:54:45 consumer333 slapd[23500]: do_syncrep2: rid=333 LDAP_RES_INTERMEDIATE - REFRESH_DELETE 
Feb 25 18:54:46 consumer333 slapd[23505]: [OK] OpenLDAP started
Feb 25 19:29:14 consumer333 slapd[2318]: [INFO] Using /etc/default/slapd for configuration Feb 25 19:29:14 consumer333 slapd[2323]: [INFO] Launching OpenLDAP configuration test... Feb 25 19:29:15 consumer333 slapd[2346]: [OK] OpenLDAP configuration test successful 
Feb 25 19:29:15 consumer333 slapd[2356]: [INFO] No db_recover done
Feb 25 19:29:15 consumer333 slapd[2357]: [INFO] Launching OpenLDAP...
Feb 25 19:29:15 consumer333 slapd[2358]: [OK] File descriptor limit set to 1024 Feb 25 19:29:15 consumer333 slapd[2359]: @(#) $OpenLDAP: slapd 2.4.X (Feb 25 2012 18:38:31) $ swbuilder@vdev.example.com:/home/swbuilder/rpmbuild/BUILD/openldap-2.4.30b3/servers/slapd 
Feb 25 19:29:15 consumer333 slapd[2360]: slapd starting
Feb 25 19:29:15 consumer333 slapd[2360]: do_syncrep2: rid=333 LDAP_RES_INTERMEDIATE - REFRESH_DELETE 
Feb 25 19:29:16 consumer333 slapd[2365]: [OK] OpenLDAP started
Feb 25 20:02:42 consumer333 slapd[2943]: [INFO] Using /etc/default/slapd for configuration 
Feb 25 20:02:42 consumer333 slapd[2948]: [INFO] Halting OpenLDAP...
Feb 25 20:02:42 consumer333 slapd[2360]: daemon: shutdown requested and initiated. Feb 25 20:02:42 consumer333 slapd[2360]: slapd shutdown: waiting for 1 operations/tasks to finish 
Feb 25 20:02:42 consumer333 slapd[2360]: slapd stopped.
Feb 25 20:02:43 consumer333 slapd[2952]: [OK] OpenLDAP stopped after 1 seconds 
Feb 25 20:02:43 consumer333 slapd[2953]: [INFO] No data backup done
Feb 25 20:02:55 consumer333 slapd[2983]: [INFO] Using /etc/default/slapd for configuration Feb 25 20:02:55 consumer333 slapd[2988]: [INFO] Launching OpenLDAP configuration test... Feb 25 20:02:55 consumer333 slapd[3011]: [OK] OpenLDAP configuration test successful 
Feb 25 20:02:55 consumer333 slapd[3021]: [INFO] No db_recover done
Feb 25 20:02:55 consumer333 slapd[3022]: [INFO] Launching OpenLDAP...
Feb 25 20:02:55 consumer333 slapd[3023]: [OK] File descriptor limit set to 1024 Feb 25 20:02:55 consumer333 slapd[3024]: @(#) $OpenLDAP: slapd 2.4.X (Feb 25 2012 18:38:31) $ swbuilder@vdev.example.com:/home/swbuilder/rpmbuild/BUILD/openldap-2.4.30b3/servers/slapd 
Feb 25 20:02:55 consumer333 slapd[3025]: slapd starting
Feb 25 20:02:55 consumer333 slapd[3025]: syncrepl_message_to_entry: rid=333 DN: dc=bridge-o.admin,dc=example.com,ou=dns1,dc=example,dc=com, UUID: a483715a-56bd-102f-9a9d-87b8bcc59e1e Feb 25 20:02:55 consumer333 slapd[3025]: syncrepl_entry: rid=333 LDAP_RES_SEARCH_ENTRY(LDAP_SYNC_ADD) 
...sync continues...

Questions:

1. What does the message "connection_read(35): no connection!" signify?
(On this consumer -only- I also get occasional messages, like the following: Feb 27 22:25:56 consumer111 slapd[2939]: connection_input: conn=1001 deferring operation: binding 
   )
2. Why there was a stop in retrying for two hours on the running consumers (111, 222)?
3. Why the upgraded consumer (333) did not sync? It was started after the provider and it was running when the changes were made on the provider. 

Thanks,
Nick