All,
I turned off TLS on both MMR machines, so I could more easily troubleshoot Syncrepl/MMR configuration. Once over this hurdle, I'll re-incorporate TLS.
The following is a snippet of the SLAPD output-log file:
<MM-SERVER2> 52efa558 => bdb_dn2id("cn=replicator,cn=accesslog") 52efa558 <= bdb_dn2id: get failed: DB_NOTFOUND: No matching key/data pair found (-30989) 52efa558 send_ldap_result: conn=5226 op=0 p=3 52efa558 send_ldap_result: err=49 matched="" text="" 52efa558 send_ldap_response: msgid=1 tag=97 err=49 ber_flush2: 14 bytes to sd 30 0000: 30 0c 02 01 01 61 07 0a 01 31 04 00 04 00 0....a...1.... ldap_write: want=14, written=14 0000: 30 0c 02 01 01 61 07 0a 01 31 04 00 04 00 0....a...1.... 52efa558 conn=5226 op=0 RESULT tag=97 err=49 text= 52efa558 daemon: activity on 1 descriptor 52efa558 daemon: activity on:52efa558 52efa558 daemon: epoll: listen=7 active_threads=0 tvp=zero 52efa558 daemon: activity on 1 descriptor 52efa558 daemon: activity on:52efa558 30r52efa558 52efa558 daemon: read active on 30 52efa558 daemon: epoll: listen=7 active_threads=0 tvp=zero 52efa558 connection_get(30) 52efa558 connection_get(30): got connid=5226 52efa558 connection_read(30): checking for input on id=5226 ber_get_next ldap_read: want=8, got=7 0000: 30 05 02 01 02 42 00 0....B. ber_get_next: tag 0x30 len 5 contents: ber_dump: buf=0x1ba86150 ptr=0x1ba86150 end=0x1ba86155 len=5 0000: 02 01 02 42 00 ...B. 52efa558 op tag 0x42, time 1391437144 ber_get_next ldap_read: want=8, got=0
52efa558 ber_get_next on fd 30 failed errno=0 (Success) 52efa558 connection_read(30): input error=-2 id=5226, closing. 52efa558 connection_closing: readying conn=5226 sd=30 for close 52efa558 connection_close: deferring conn=5226 sd=30 52efa558 conn=5226 op=1 do_unbind 52efa558 conn=5226 op=1 UNBIND 52efa558 connection_resched: attempting closing conn=5226 sd=30 52efa558 connection_close: conn=5226 sd=30 52efa558 daemon: removing 30 52efa558 conn=5226 fd=30 closed 52efa558 daemon: activity on 1 descriptor 52efa558 daemon: activity on:52efa558 52efa558 daemon: epoll: listen=7 active_threads=0 tvp=zero 52efa57c daemon: epoll: listen=7 active_threads=0 tvp=zero 52efa57c =>do_syncrepl rid=001 ldap_create ldap_url_parse_ext(ldap://mm-server1.example.ldap) ldap_sasl_bind_s ldap_sasl_bind ldap_send_initial_request ldap_new_connection 1 1 0 ldap_int_open_connection ldap_connect_to_host: TCP mm-server1.example.ldap:389 ldap_new_socket: 30 ldap_prepare_socket: 30 ldap_connect_to_host: Trying mm-server1-IP_Addr:389 ldap_pvt_connect: fd: 30 tm: -1 async: 0 attempting to connect: connect success ldap_open_defconn: successful ldap_send_server_request ber_scanf fmt ({it) ber: ber_dump: buf=0x1ba7fb60 ptr=0x1ba7fb60 end=0x1ba7fb93 len=51 0000: 30 31 02 01 01 60 2c 02 01 03 04 1a 63 6e 3d 72 01...`,.....cn=r 0010: 65 70 6c 69 63 61 74 6f 72 2c 63 6e 3d 61 63 63 eplicator,cn=acc 0020: 65 73 73 6c 6f 67 80 0b 47 72 70 34 32 2d 41 64 esslog..<replicator-password> 0030: 6d 31 6e m1n ber_scanf fmt ({i) ber: ber_dump: buf=0x1ba7fb60 ptr=0x1ba7fb65 end=0x1ba7fb93 len=46 0000: 60 2c 02 01 03 04 1a 63 6e 3d 72 65 70 6c 69 63 `,.....cn=replic 0010: 61 74 6f 72 2c 63 6e 3d 61 63 63 65 73 73 6c 6f ator,cn=accesslo 0020: 67 80 0b 47 72 70 34 32 2d 41 64 6d 31 6e g..<replicator-password> ber_flush2: 51 bytes to sd 30 0000: 30 31 02 01 01 60 2c 02 01 03 04 1a 63 6e 3d 72 01...`,.....cn=r 0010: 65 70 6c 69 63 61 74 6f 72 2c 63 6e 3d 61 63 63 eplicator,cn=acc 0020: 65 73 73 6c 6f 67 80 0b 47 72 70 34 32 2d 41 64 esslog..<replicator-password> 0030: 6d 31 6e m1n ldap_write: want=51, written=51 0000: 30 31 02 01 01 60 2c 02 01 03 04 1a 63 6e 3d 72 01...`,.....cn=r 0010: 65 70 6c 69 63 61 74 6f 72 2c 63 6e 3d 61 63 63 eplicator,cn=acc 0020: 65 73 73 6c 6f 67 80 0b 47 72 70 34 32 2d 41 64 esslog..<replicator-password> 0030: 6d 31 6e m1n ldap_result ld 0x1ba7b1c0 msgid 1 wait4msg ld 0x1ba7b1c0 msgid 1 (infinite timeout) wait4msg continue ld 0x1ba7b1c0 msgid 1 all 1 ** ld 0x1ba7b1c0 Connections: * host: mm-server1.example.ldap port: 389 (default) refcnt: 2 status: Connected last used: Mon Feb 3 09:19:40 2014
** ld 0x1ba7b1c0 Outstanding Requests: * msgid 1, origid 1, status InProgress outstanding referrals 0, parent count 0 ld 0x1ba7b1c0 request count 1 (abandoned 0) ** ld 0x1ba7b1c0 Response Queue: Empty ld 0x1ba7b1c0 response count 0 ldap_chkResponseList ld 0x1ba7b1c0 msgid 1 all 1 ldap_chkResponseList returns ld 0x1ba7b1c0 NULL ldap_int_select read1msg: ld 0x1ba7b1c0 msgid 1 all 1 ber_get_next ldap_read: want=8, got=8 0000: 30 0c 02 01 01 61 07 0a 0....a.. ldap_read: want=6, got=6 0000: 01 31 04 00 04 00 .1.... ber_get_next: tag 0x30 len 12 contents: ber_dump: buf=0x1ba0dc60 ptr=0x1ba0dc60 end=0x1ba0dc6c len=12 0000: 02 01 01 61 07 0a 01 31 04 00 04 00 ...a...1.... read1msg: ld 0x1ba7b1c0 msgid 1 message type bind ber_scanf fmt ({eAA) ber: ber_dump: buf=0x1ba0dc60 ptr=0x1ba0dc63 end=0x1ba0dc6c len=9 0000: 61 07 0a 01 31 04 00 04 00 a...1.... read1msg: ld 0x1ba7b1c0 0 new referrals read1msg: mark request completed, ld 0x1ba7b1c0 msgid 1 request done: ld 0x1ba7b1c0 msgid 1 res_errno: 49, res_error: <>, res_matched: <> ldap_free_request (origid 1, msgid 1) ldap_parse_result ber_scanf fmt ({iAA) ber: ber_dump: buf=0x1ba0dc60 ptr=0x1ba0dc63 end=0x1ba0dc6c len=9 0000: 61 07 0a 01 31 04 00 04 00 a...1.... ber_scanf fmt (}) ber: ber_dump: buf=0x1ba0dc60 ptr=0x1ba0dc6c end=0x1ba0dc6c len=0
ldap_msgfree 52efa57c slap_client_connect: URI=ldap://mm-server1.example.ldap DN="cn=replicator,cn=accesslog" ldap_sasl_bind_s failed (49) ldap_free_connection 1 1 ldap_send_unbind ber_flush2: 7 bytes to sd 30 0000: 30 05 02 01 02 42 00 0....B. ldap_write: want=7, written=7 0000: 30 05 02 01 02 42 00 0....B. ldap_free_connection: actually freed 52efa57c do_syncrepl: rid=001 rc 49 retrying 52efa57c daemon: activity on 1 descriptor 52efa57c daemon: activity on:52efa57c 52efa57c daemon: epoll: listen=7 active_threads=0 tvp=zero 52efa594 daemon: activity on 1 descriptor 52efa594 daemon: activity on:52efa594 52efa594 slap_listener_activate(7): 52efa594 daemon: epoll: listen=7 busy 52efa594 >>> slap_listener(ldap://mm-server2.example.ldap) 52efa594 daemon: listen=7, new connection on 30 52efa594 daemon: added 30r (active) listener=(nil) 52efa594 conn=5227 fd=30 ACCEPT from IP=mm-server1-IP_Addr:56515 (IP=<mm-server2-IP_Addr>:389) 52efa594 daemon: activity on 2 descriptors 52efa594 daemon: activity on:52efa594 30r52efa594 52efa594 daemon: read active on 30 52efa594 daemon: epoll: listen=7 active_threads=0 tvp=zero 52efa594 connection_get(30) 52efa594 connection_get(30): got connid=5227 52efa594 connection_read(30): checking for input on id=5227 ber_get_next ldap_read: want=8, got=8 0000: 30 31 02 01 01 60 2c 02 01...`,. ldap_read: want=43, got=43 0000: 01 03 04 1a 63 6e 3d 72 65 70 6c 69 63 61 74 6f ....cn=replicato 0010: 72 2c 63 6e 3d 61 63 63 65 73 73 6c 6f 67 80 0b r,cn=accesslog.. 0020: 47 72 70 34 32 2d 41 64 6d 31 6e <replicator-password> ber_get_next: tag 0x30 len 49 contents: ber_dump: buf=0x1b9fefa0 ptr=0x1b9fefa0 end=0x1b9fefd1 len=49 0000: 02 01 01 60 2c 02 01 03 04 1a 63 6e 3d 72 65 70 ...`,.....cn=rep 0010: 6c 69 63 61 74 6f 72 2c 63 6e 3d 61 63 63 65 73 licator,cn=acces 0020: 73 6c 6f 67 80 0b 47 72 70 34 32 2d 41 64 6d 31 slog..<replicator-password> 0030: 6e n 52efa594 op tag 0x60, time 1391437204 ber_get_next
I can see that syncrepl is being attempted, but the: 52efa558 <= bdb_dn2id: get failed: DB_NOTFOUND: No matching key/data pair found (-30989) ... is bothering me...
Thanks in advance John
-----Original Message----- From: Quanah Gibson-Mount [mailto:quanah@zimbra.com] Sent: Friday, January 31, 2014 4:37 PM To: Borresen, John - 0442 - MITLL; openldap-technical@openldap.org Subject: RE: Syncrepl and mmr
--On Friday, January 31, 2014 4:34 PM -0500 "Borresen, John - 0442 - MITLL" John.Borresen@ll.mit.edu wrote:
I have turned off TLS for the time being.
Now, I think it is an ACLs issue that I need to figure out...seeing the following:
ldap_write: want=531 error=Broken pipe 52ec16ae ber_flush2 failed errno=32 reason="Broken pipe" 52ec16ae connection_closing: readying conn=1074 sd=22 for close 52ec16ae send_search_entry: conn 1074 ber write failed. 52ec16ae connection_resched: attempting closing conn=1074 sd=22 52ec16ae connection_close: conn=1074 sd=22 52ec16ae daemon: removing 22 52ec16ae conn=1074 fd=22 closed (connection lost on write) 52ec16ae daemon: activity on 1 descriptor 52ec16ae daemon: activity on:52ec16ae 52ec16ae daemon: epoll: listen=7 active_threads=0 tvp=zero
That would not be an acl issue. broken pipes, flushing problems, etc... I generally see that with firewalls causing problems.
--Quanah
--
Quanah Gibson-Mount Architect - Server Zimbra, Inc. -------------------- Zimbra :: the leader in open source messaging and collaboration