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
On 3/3/2012 12:31 μμ, Nick Milas wrote:
- 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)?
- 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.
Any hint on these issues, please?
Thanks, Nick
--On Tuesday, March 06, 2012 11:36 PM +0200 Nick Milas nick@eurobjects.com wrote:
On 3/3/2012 12:31 μμ, Nick Milas wrote:
- What does the message "connection_read(35): no connection!" signify? (On this consumer -only- I also get occasional messages, like the
following:
connection_read has been asked and answered a few hundred times on the list. It means a client has disconnected without sending an unbind request.
Feb 27 22:25:56 consumer111 slapd[2939]: connection_input:
conn=1001 deferring operation: binding )
It means the server is currently busy, so it is deferring the operation request.
- Why there was a stop in retrying for two hours on the running
consumers (111, 222)?
No idea. I haven't seen this issue.
- 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.
No idea. I haven't seen this issue.
--Quanah
--
Quanah Gibson-Mount Sr. Member of Technical Staff Zimbra, Inc A Division of VMware, Inc. -------------------- Zimbra :: the leader in open source messaging and collaboration
openldap-technical@openldap.org