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