All, Hope I am not persona non grata (that is supposed to be funny) based on the responses I received from my last post earlier today. Tomorrow I am starting from scratch…I have one week to get this working -- afraid to find out what will happen after that. Anyway, I’ve increased the syslog verbosity on both servers. mm-server1: 52fbefc2 <= send_search_entry: conn 1013 exit. 52fbefc2 => test_filter 52fbefc2 PRESENT 52fbefc2 => access_allowed: search access to "reqStart=20140211203819.000000Z,cn=accesslog" "objectClass" requested 52fbefc2 => acl_get: [1] attr objectClass 52fbefc2 => acl_mask: access to entry "reqStart=20140211203819.000000Z,cn=accesslog", attr "objectClass" requested 52fbefc2 => acl_mask: to all values by "cn=ldapadmin,dc=group42,dc=ldap", (=0) 52fbefc2 <= check a_dn_pat: uid=replicator,ou=admins,dc=group42,dc=ldap 52fbefc2 <= check a_dn_pat: cn=ldapadmin,dc=group42,dc=ldap 52fbefc2 <= acl_mask: [2] applying write(=wrscxd) (stop) 52fbefc2 <= acl_mask: [2] mask: write(=wrscxd) 52fbefc2 => slap_access_allowed: search access granted by write(=wrscxd) 52fbefc2 => access_allowed: search access granted by write(=wrscxd) 52fbefc2 <= test_filter 6 52fbefc2 => send_search_entry: conn 1013 dn="reqStart=20140211203819.000000Z,cn=accesslog" 52fbefc2 => access_allowed: read access to "reqStart=20140211203819.000000Z,cn=accesslog" "entry" requested 52fbefc2 => acl_get: [1] attr entry 52fbefc2 => acl_mask: access to entry "reqStart=20140211203819.000000Z,cn=accesslog", attr "entry" requested 52fbefc2 => acl_mask: to all values by "cn=ldapadmin,dc=group42,dc=ldap", (=0) 52fbefc2 <= check a_dn_pat: uid=replicator,ou=admins,dc=group42,dc=ldap 52fbefc2 <= check a_dn_pat: cn=ldapadmin,dc=group42,dc=ldap 52fbefc2 <= acl_mask: [2] applying write(=wrscxd) (stop) 52fbefc2 <= acl_mask: [2] mask: write(=wrscxd) 52fbefc2 => slap_access_allowed: read access granted by write(=wrscxd) 52fbefc2 => access_allowed: read access granted by write(=wrscxd) 52fbefc2 => access_allowed: result not in cache (reqType) 52fbefc2 => access_allowed: read access to "reqStart=20140211203819.000000Z,cn=accesslog" "reqType" requested 52fbefc2 => acl_get: [1] attr reqType 52fbefc2 => acl_mask: access to entry "reqStart=20140211203819.000000Z,cn=accesslog", attr "reqType" requested 52fbefc2 => acl_mask: to value by "cn=ldapadmin,dc=group42,dc=ldap", (=0) 52fbefc2 <= check a_dn_pat: uid=replicator,ou=admins,dc=group42,dc=ldap 52fbefc2 <= check a_dn_pat: cn=ldapadmin,dc=group42,dc=ldap 52fbefc2 <= acl_mask: [2] applying write(=wrscxd) (stop) 52fbefc2 <= acl_mask: [2] mask: write(=wrscxd) 52fbefc2 => slap_access_allowed: read access granted by write(=wrscxd) 52fbefc2 => access_allowed: read access granted by write(=wrscxd) 52fbefc2 => access_allowed: result not in cache (reqDN) 52fbefc2 => access_allowed: read access to "reqStart=20140211203819.000000Z,cn=accesslog" "reqDN" requested 52fbefc2 => acl_get: [1] attr reqDN 52fbefc2 => acl_mask: access to entry "reqStart=20140211203819.000000Z,cn=accesslog", attr "reqDN" requested 52fbefc2 => acl_mask: to value by "cn=ldapadmin,dc=group42,dc=ldap", (=0) 52fbefc2 <= check a_dn_pat: uid=replicator,ou=admins,dc=group42,dc=ldap 52fbefc2 <= check a_dn_pat: cn=ldapadmin,dc=group42,dc=ldap 52fbefc2 <= acl_mask: [2] applying write(=wrscxd) (stop) 52fbefc2 <= acl_mask: [2] mask: write(=wrscxd) 52fbefc2 => slap_access_allowed: read access granted by write(=wrscxd) 52fbefc2 => access_allowed: read access granted by write(=wrscxd) 52fbefc2 => access_allowed: result not in cache (reqMod) 52fbefc2 => access_allowed: read access to "reqStart=20140211203819.000000Z,cn=accesslog" "reqMod" requested 52fbefc2 => acl_get: [1] attr reqMod 52fbefc2 => acl_mask: access to entry "reqStart=20140211203819.000000Z,cn=accesslog", attr "reqMod" requested 52fbefc2 => acl_mask: to value by "cn=ldapadmin,dc=group42,dc=ldap", (=0) 52fbefc2 <= check a_dn_pat: uid=replicator,ou=admins,dc=group42,dc=ldap 52fbefc2 <= check a_dn_pat: cn=ldapadmin,dc=group42,dc=ldap 52fbefc2 <= acl_mask: [2] applying write(=wrscxd) (stop) 52fbefc2 <= acl_mask: [2] mask: write(=wrscxd) 52fbefc2 => slap_access_allowed: read access granted by write(=wrscxd) 52fbefc2 => access_allowed: read access granted by write(=wrscxd) 52fbefc2 => access_allowed: result was in cache (reqMod) 52fbefc2 => access_allowed: result was in cache (reqMod) 52fbefc2 => access_allowed: result was in cache (reqMod) 52fbefc2 => access_allowed: result not in cache (entryCSN) 52fbefc2 => access_allowed: read access to "reqStart=20140211203819.000000Z,cn=accesslog" "entryCSN" requested 52fbefc2 => acl_get: [1] attr entryCSN 52fbefc2 => acl_mask: access to entry "reqStart=20140211203819.000000Z,cn=accesslog", attr "entryCSN" requested 52fbefc2 => acl_mask: to value by "cn=ldapadmin,dc=group42,dc=ldap", (=0) 52fbefc2 <= check a_dn_pat: uid=replicator,ou=admins,dc=group42,dc=ldap 52fbefc2 <= check a_dn_pat: cn=ldapadmin,dc=group42,dc=ldap 52fbefc2 <= acl_mask: [2] applying write(=wrscxd) (stop) 52fbefc2 <= acl_mask: [2] mask: write(=wrscxd) 52fbefc2 => slap_access_allowed: read access granted by write(=wrscxd) 52fbefc2 => access_allowed: read access granted by write(=wrscxd) 52fbefc2 conn=1013 op=1 ENTRY dn="reqStart=20140211203819Z,cn=accesslog" 52fbefc2 daemon: activity on 1 descriptor 52fbefc2 daemon: activity on:52fbefc2 18r52fbefc2 52fbefc2 daemon: read active on 18 52fbefc2 daemon: epoll: listen=7 active_threads=0 tvp=zero 52fbefc2 daemon: activity on 1 descriptor 52fbefc2 daemon: activity on:52fbefc2 52fbefc2 daemon: epoll: listen=7 active_threads=0 tvp=zero 52fbefc2 daemon: activity on 1 descriptor 52fbefc2 daemon: activity on:52fbefc2 52fbefc2 daemon: epoll: listen=7 active_threads=0 tvp=zero 52fbefc2 connection_get(18) 52fbefc2 connection_get(18): got connid=1013 52fbefc2 connection_read(18): checking for input on id=1013 ber_get_next ldap_read: want=8, got=7 0000: 30 05 02 01 03 42 00 0....B. ber_get_next: tag 0x30 len 5 contents: ber_dump: buf=0x76a43d0 ptr=0x76a43d0 end=0x76a43d5 len=5 0000: 02 01 03 42 00 ...B. 52fbefc2 op tag 0x42, time 1392242626 ber_get_next ldap_read: want=8, got=0 mm-server2: 52fbf12a =>do_syncrep2 rid=001 ldap_result ld 0x9715890 msgid 2 wait4msg ld 0x9715890 msgid 2 (infinite timeout) wait4msg continue ld 0x9715890 msgid 2 all 0 ** ld 0x9715890 Connections: * host: mm-server1.example.ldap port: 389 (default) refcnt: 2 status: Connected last used: Wed Feb 12 17:09:46 2014 ** ld 0x9715890 Outstanding Requests: * msgid 2, origid 2, status InProgress outstanding referrals 0, parent count 0 ld 0x9715890 request count 1 (abandoned 0) ** ld 0x9715890 Response Queue: Empty ld 0x9715890 response count 0 ldap_chkResponseList ld 0x9715890 msgid 2 all 0 ldap_chkResponseList returns ld 0x9715890 NULL ldap_int_select read1msg: ld 0x9715890 msgid 2 all 0 ber_get_next ldap_read: want=8, got=8 0000: 30 81 b2 02 01 02 64 48 0.....dH ldap_read: want=173, got=173 0000: 04 0c 63 6e 3d 61 63 63 65 73 73 6c 6f 67 30 38 ..cn=accesslog08 0010: 30 36 04 08 65 6e 74 72 79 43 53 4e 31 2a 04 28 06..entryCSN1*.( 0020: 32 30 31 34 30 32 30 33 31 38 33 38 33 31 2e 37 20140203183831.7 0030: 35 31 38 33 38 5a 23 30 30 30 30 30 30 23 30 30 51838Z#000000#00 0040: 31 23 30 30 30 30 30 30 a0 63 30 61 04 18 31 2e 1#000000.c0a..1. 0050: 33 2e 36 2e 31 2e 34 2e 31 2e 34 32 30 33 2e 31 3.6.1.4.1.4203.1 0060: 2e 39 2e 31 2e 32 04 45 30 43 0a 01 01 04 00 04 .9.1.2.E0C...... 0070: 3c 72 69 64 3d 30 30 31 2c 73 69 64 3d 30 30 31 <rid=001,sid=001 0080: 2c 63 73 6e 3d 32 30 31 34 30 32 30 33 31 38 33 ,csn=20140203183 0090: 38 33 31 2e 37 35 31 38 33 38 5a 23 30 30 30 30 831.751838Z#0000 00a0: 30 30 23 30 30 31 23 30 30 30 30 30 30 00#001#000000 ber_get_next: tag 0x30 len 178 contents: ber_dump: buf=0x9762840 ptr=0x9762840 end=0x97628f2 len=178 0000: 02 01 02 64 48 04 0c 63 6e 3d 61 63 63 65 73 73 ...dH..cn=access 0010: 6c 6f 67 30 38 30 36 04 08 65 6e 74 72 79 43 53 log0806..entryCS 0020: 4e 31 2a 04 28 32 30 31 34 30 32 30 33 31 38 33 N1*.(20140203183 0030: 38 33 31 2e 37 35 31 38 33 38 5a 23 30 30 30 30 831.751838Z#0000 0040: 30 30 23 30 30 31 23 30 30 30 30 30 30 a0 63 30 00#001#000000.c0 0050: 61 04 18 31 2e 33 2e 36 2e 31 2e 34 2e 31 2e 34 a..1.3.6.1.4.1.4 0060: 32 30 33 2e 31 2e 39 2e 31 2e 32 04 45 30 43 0a 203.1.9.1.2.E0C. 0070: 01 01 04 00 04 3c 72 69 64 3d 30 30 31 2c 73 69 .....<rid=001,si 0080: 64 3d 30 30 31 2c 63 73 6e 3d 32 30 31 34 30 32 d=001,csn=201402 0090: 30 33 31 38 33 38 33 31 2e 37 35 31 38 33 38 5a 03183831.751838Z 00a0: 23 30 30 30 30 30 30 23 30 30 31 23 30 30 30 30 #000000#001#0000 00b0: 30 30 00 read1msg: ld 0x9715890 msgid 2 message type search-entry ber_scanf fmt ({xx) ber: ber_dump: buf=0x9762840 ptr=0x9762843 end=0x97628f2 len=175 0000: 64 48 04 0c 63 6e 3d 61 63 63 65 73 73 6c 6f 67 dH..cn=accesslog 0010: 30 38 30 36 04 08 65 6e 74 72 79 43 53 4e 31 2a 0806..entryCSN1* 0020: 04 28 32 30 31 34 30 32 30 33 31 38 33 38 33 31 .(20140203183831 0030: 2e 37 35 31 38 33 38 5a 23 30 30 30 30 30 30 23 .751838Z#000000# 0040: 30 30 31 23 30 30 30 30 30 30 a0 63 30 61 04 18 001#000000.c0a.. 0050: 31 2e 33 2e 36 2e 31 2e 34 2e 31 2e 34 32 30 33 1.3.6.1.4.1.4203 0060: 2e 31 2e 39 2e 31 2e 32 04 45 30 43 0a 01 01 04 .1.9.1.2.E0C.... 0070: 00 04 3c 72 69 64 3d 30 30 31 2c 73 69 64 3d 30 ..<rid=001,sid=0 0080: 30 31 2c 63 73 6e 3d 32 30 31 34 30 32 30 33 31 01,csn=201402031 0090: 38 33 38 33 31 2e 37 35 31 38 33 38 5a 23 30 30 83831.751838Z#00 00a0: 30 30 30 30 23 30 30 31 23 30 30 30 30 30 30 0000#001#000000 ber_scanf fmt ({a) ber: ber_dump: buf=0x9762840 ptr=0x976288f end=0x97628f2 len=99 0000: 30 61 04 18 31 2e 33 2e 36 2e 31 2e 34 2e 31 2e 0a..1.3.6.1.4.1. 0010: 34 32 30 33 2e 31 2e 39 2e 31 2e 32 04 45 30 43 4203.1.9.1.2.E0C 0020: 0a 01 01 04 00 04 3c 72 69 64 3d 30 30 31 2c 73 ......<rid=001,s 0030: 69 64 3d 30 30 31 2c 63 73 6e 3d 32 30 31 34 30 id=001,csn=20140 0040: 32 30 33 31 38 33 38 33 31 2e 37 35 31 38 33 38 203183831.751838 0050: 5a 23 30 30 30 30 30 30 23 30 30 31 23 30 30 30 Z#000000#001#000 0060: 30 30 30 000 ber_scanf fmt (o) ber: ber_dump: buf=0x9762840 ptr=0x97628ab end=0x97628f2 len=71 0000: 04 45 30 43 0a 01 01 04 00 04 3c 72 69 64 3d 30 .E0C......<rid=0 0010: 30 31 2c 73 69 64 3d 30 30 31 2c 63 73 6e 3d 32 01,sid=001,csn=2 0020: 30 31 34 30 32 30 33 31 38 33 38 33 31 2e 37 35 0140203183831.75 0030: 31 38 33 38 5a 23 30 30 30 30 30 30 23 30 30 31 1838Z#000000#001 0040: 23 30 30 30 30 30 30 #000000 ldap_get_dn_ber ber_scanf fmt ({ml{) ber: ber_dump: buf=0x9762840 ptr=0x9762843 end=0x97628f2 len=175 0000: 64 48 04 0c 63 6e 3d 61 63 63 65 73 73 6c 6f 67 dH..cn=accesslog 0010: 30 38 30 36 04 08 65 6e 74 72 79 43 53 4e 31 2a 0806..entryCSN1* 0020: 04 28 32 30 31 34 30 32 30 33 31 38 33 38 33 31 .(20140203183831 0030: 2e 37 35 31 38 33 38 5a 23 30 30 30 30 30 30 23 .751838Z#000000# 0040: 30 30 31 23 30 30 30 30 30 30 a0 63 30 61 04 18 001#000000.c0a.. 0050: 31 2e 33 2e 36 2e 31 2e 34 2e 31 2e 34 32 30 33 1.3.6.1.4.1.4203 0060: 2e 31 2e 39 2e 31 2e 32 04 45 30 43 0a 01 01 04 .1.9.1.2.E0C.... 0070: 00 04 3c 72 69 64 3d 30 30 31 2c 73 69 64 3d 30 ..<rid=001,sid=0 0080: 30 31 2c 63 73 6e 3d 32 30 31 34 30 32 30 33 31 01,csn=201402031 0090: 38 33 38 33 31 2e 37 35 31 38 33 38 5a 23 30 30 83831.751838Z#00 00a0: 30 30 30 30 23 30 30 31 23 30 30 30 30 30 30 0000#001#000000 ber_scanf fmt ({em) ber: ber_dump: buf=0x9762970 ptr=0x9762970 end=0x97629b5 len=69 0000: 30 43 0a 01 01 04 00 04 3c 72 69 64 3d 30 30 31 0C......<rid=001 0010: 2c 73 69 64 3d 30 30 31 2c 63 73 6e 3d 32 30 31 ,sid=001,csn=201 0020: 34 30 32 30 33 31 38 33 38 33 31 2e 37 35 31 38 40203183831.7518 0030: 33 38 5a 23 30 30 30 30 30 30 23 30 30 31 23 30 38Z#000000#001#0 0040: 30 30 30 30 30 00000 52fbf12a do_syncrep2: rid=001 got empty syncUUID with LDAP_SYNC_ADD (cn=accesslog) ldap_msgfree ldap_free_request (origid 2, msgid 2) ldap_free_connection 1 1 ldap_send_unbind ber_flush2: 7 bytes to sd 17 0000: 30 05 02 01 03 42 00 0....B. ldap_write: want=7, written=7 0000: 30 05 02 01 03 42 00 0....B. ldap_free_connection: actually freed 52fbf12a do_syncrepl: rid=001 rc -1 retrying 52fbf12a daemon: activity on 1 descriptor 52fbf12a daemon: activity on:52fbf12a 52fbf12a daemon: epoll: listen=7 active_threads=0 tvp=zero 52fbf166 daemon: epoll: listen=7 active_threads=0 tvp=zero 52fbf166 =>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: 17 ldap_prepare_socket: 17 ldap_connect_to_host: Trying <mm-server1_IP>:389 ldap_pvt_connect: fd: 17 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=0x9761740 ptr=0x9761740 end=0x9761778 len=56 0000: 30 36 02 01 01 60 31 02 01 03 04 1f 63 6e 3d 6c 06...`1.....cn=l 0010: 64 61 70 61 64 6d 69 6e 2c 64 63 3d 67 72 6f 75 dapadmin,dc=exam 0020: 70 34 32 2c 64 63 3d 6c 64 61 70 80 0b 47 72 70 ple,dc=ldap..<pas 0030: 34 32 2d 41 64 6d 21 6e sword> ber_scanf fmt ({i) ber: ber_dump: buf=0x9761740 ptr=0x9761745 end=0x9761778 len=51 0000: 60 31 02 01 03 04 1f 63 6e 3d 6c 64 61 70 61 64 `1.....cn=ldapad 0010: 6d 69 6e 2c 64 63 3d 67 72 6f 75 70 34 32 2c 64 min,dc=example,d 0020: 63 3d 6c 64 61 70 80 0b 47 72 70 34 32 2d 41 64 c=ldap..<passwo 0030: 6d 21 6e rd> ber_flush2: 56 bytes to sd 17 0000: 30 36 02 01 01 60 31 02 01 03 04 1f 63 6e 3d 6c 06...`1.....cn=l 0010: 64 61 70 61 64 6d 69 6e 2c 64 63 3d 67 72 6f 75 dapadmin,dc=grou 0020: 70 34 32 2c 64 63 3d 6c 64 61 70 80 0b 47 72 70 p42,dc=ldap..<pass 0030: 34 32 2d 41 64 6d 21 6e word> ldap_write: want=56, written=56 0000: 30 36 02 01 01 60 31 02 01 03 04 1f 63 6e 3d 6c 06...`1.....cn=l 0010: 64 61 70 61 64 6d 69 6e 2c 64 63 3d 67 72 6f 75 dapadmin,dc=grou 0020: 70 34 32 2c 64 63 3d 6c 64 61 70 80 0b 47 72 70 p42,dc=ldap..<pas 0030: 34 32 2d 41 64 6d 21 6e sword> ldap_result ld 0x950ac90 msgid 1 Thanks in advance… John D. Borresen (Dave) Linux/Unix Systems Administrator MIT Lincoln Laboratory Surveillance Systems Group 244 Wood St Lexington, MA 02420 Email: john.borresen@ll.mit.edu |