groups added to provider not replicating to consumer

hi-

i've recently set up delta-syncrepl, with one provider and one consumer. things seemed to be generally working, but i recently noticed that member attributes in group entries were not getting replicated. after a bit of testing, i also found that new groups added to the provider appear to not be replicated to the consumer. it also appears that the operation of adding a group is not being written to the accesslog. on a possibly related note, i'm using the memberof overlay, and the memberof attribute modifications which occur as a result of adding a group are written to the accesslog, and are replicated to the consumer. i'm using 2.4.25, courtesy of ubuntu 11.10. what can i do to better understand what is happening, and why? below is some preliminary data, and log entries using olcloglevel: any

thanks -ben

cat add_group.ldif

dn: cn=test_group,ou=general,ou=groups,dc=example,dc=net changetype: add objectClass: top objectClass: groupOfNames description: test group cn: test_group member: uid=dummy_default,ou=dummy_accounts,ou=other,ou=accounts,dc=example,dc=net

ldapadd -xZZD 'uid=dit_admin,ou=role_accounts,ou=accounts,dc=example,dc=net' -w 'xxxxxxxxxxxx' -f add_group.ldif

adding new entry "cn=test_group,ou=general,ou=groups,dc=example,dc=net"

subsequent ldapsearch on provider:

ldapsearch -xLLLZZD 'uid=dit_admin,ou=role_accounts,ou=accounts,dc=example,dc=net' -w 'xxxxxxxxxxxx' -b 'cn=test_group,ou=general,ou=groups,dc=example,dc=net' -s base '*' '+'

dn: cn=test_group,ou=general,ou=groups,dc=example,dc=net objectClass: top objectClass: groupOfNames description: test group cn: test_group member: uid=dummy_default,ou=dummy_accounts,ou=other,ou=accounts,dc=example, dc=net structuralObjectClass: groupOfNames entryUUID: d68c73e4-10c1-1031-8246-9dfa8daa46e0 creatorsName: uid=dit_admin,ou=role_accounts,ou=accounts,dc=example,dc=net createTimestamp: 20120402034404Z entryCSN: 20120402034404.808333Z#000000#000#000000 modifiersName: uid=dit_admin,ou=role_accounts,ou=accounts,dc=example,dc=net modifyTimestamp: 20120402034404Z entryDN: cn=test_group,ou=general,ou=groups,dc=example,dc=net subschemaSubentry: cn=Subschema hasSubordinates: FALSE

subsequent ldapsearch on consumer:

ldapsearch -xLLLZZD 'uid=dit_admin,ou=role_accounts,ou=accounts,dc=example,dc=net' -w 'xxxxxxxxxxxx' -b 'cn=test_group,ou=general,ou=groups,dc=example,dc=net' -s base '*' '+'

No such object (32) Matched DN: ou=general,ou=groups,dc=example,dc=net

provider log entries:

Apr 1 23:44:04 flip slapd[9255]: daemon: activity on 1 descriptor Apr 1 23:44:04 flip slapd[9255]: daemon: activity on: Apr 1 23:44:04 flip slapd[9255]: Apr 1 23:44:04 flip slapd[9255]: slap_listener_activate(8): Apr 1 23:44:04 flip slapd[9255]: daemon: epoll: listen=8 busy Apr 1 23:44:04 flip slapd[9255]: daemon: epoll: listen=9 active_threads=0 tvp=zero Apr 1 23:44:04 flip slapd[9255]: daemon: epoll: listen=10 active_threads=0 tvp=zero Apr 1 23:44:04 flip slapd[9255]: daemon: epoll: listen=11 active_threads=0 tvp=zero Apr 1 23:44:04 flip slapd[9255]: >>> slap_listener(ldap:///) Apr 1 23:44:04 flip slapd[9255]: daemon: listen=8, new connection on 54 Apr 1 23:44:04 flip slapd[9255]: daemon: added 54r (active) listener=(nil) Apr 1 23:44:04 flip slapd[9255]: conn=1378 fd=54 ACCEPT from IP=192.168.1.1:47610 (IP=0.0.0.0:389) Apr 1 23:44:04 flip slapd[9255]: daemon: activity on 2 descriptors Apr 1 23:44:04 flip slapd[9255]: daemon: activity on: Apr 1 23:44:04 flip slapd[9255]: 54r Apr 1 23:44:04 flip slapd[9255]: Apr 1 23:44:04 flip slapd[9255]: daemon: read active on 54 Apr 1 23:44:04 flip slapd[9255]: daemon: epoll: listen=8 active_threads=0 tvp=zero Apr 1 23:44:04 flip slapd[9255]: daemon: epoll: listen=9 active_threads=0 tvp=zero Apr 1 23:44:04 flip slapd[9255]: daemon: epoll: listen=10 active_threads=0 tvp=zero Apr 1 23:44:04 flip slapd[9255]: daemon: epoll: listen=11 active_threads=0 tvp=zero Apr 1 23:44:04 flip slapd[9255]: connection_get(54) Apr 1 23:44:04 flip slapd[9255]: connection_get(54): got connid=1378 Apr 1 23:44:04 flip slapd[9255]: connection_read(54): checking for input on id=1378 Apr 1 23:44:04 flip slapd[9255]: op tag 0x77, time 1333338244 Apr 1 23:44:04 flip slapd[9255]: daemon: activity on 1 descriptor Apr 1 23:44:04 flip slapd[9255]: daemon: activity on: Apr 1 23:44:04 flip slapd[9255]: Apr 1 23:44:04 flip slapd[9255]: daemon: epoll: listen=8 active_threads=0 tvp=zero Apr 1 23:44:04 flip slapd[9255]: daemon: epoll: listen=9 active_threads=0 tvp=zero Apr 1 23:44:04 flip slapd[9255]: daemon: epoll: listen=10 active_threads=0 tvp=zero Apr 1 23:44:04 flip slapd[9255]: daemon: epoll: listen=11 active_threads=0 tvp=zero Apr 1 23:44:04 flip slapd[9255]: conn=1378 op=0 do_extended Apr 1 23:44:04 flip slapd[9255]: conn=1378 op=0 EXT oid=1.3.6.1.4.1.1466.20037 Apr 1 23:44:04 flip slapd[9255]: do_extended: oid=1.3.6.1.4.1.1466.20037 Apr 1 23:44:04 flip slapd[9255]: conn=1378 op=0 STARTTLS Apr 1 23:44:04 flip slapd[9255]: send_ldap_extended: err=0 oid= len=0 Apr 1 23:44:04 flip slapd[9255]: send_ldap_response: msgid=1 tag=120 err=0 Apr 1 23:44:04 flip slapd[9255]: conn=1378 op=0 RESULT oid= err=0 text= Apr 1 23:44:04 flip slapd[9255]: daemon: activity on 1 descriptor Apr 1 23:44:04 flip slapd[9255]: daemon: activity on: Apr 1 23:44:04 flip slapd[9255]: 54r Apr 1 23:44:04 flip slapd[9255]: Apr 1 23:44:04 flip slapd[9255]: daemon: read active on 54 Apr 1 23:44:04 flip slapd[9255]: daemon: epoll: listen=8 active_threads=0 tvp=zero Apr 1 23:44:04 flip slapd[9255]: daemon: epoll: listen=9 active_threads=0 tvp=zero Apr 1 23:44:04 flip slapd[9255]: daemon: epoll: listen=10 active_threads=0 tvp=zero Apr 1 23:44:04 flip slapd[9255]: daemon: epoll: listen=11 active_threads=0 tvp=zero Apr 1 23:44:04 flip slapd[9255]: connection_get(54) Apr 1 23:44:04 flip slapd[9255]: connection_get(54): got connid=1378 Apr 1 23:44:04 flip slapd[9255]: connection_read(54): checking for input on id=1378 Apr 1 23:44:04 flip slapd[9255]: daemon: activity on 1 descriptor Apr 1 23:44:04 flip slapd[9255]: daemon: activity on: Apr 1 23:44:04 flip slapd[9255]: Apr 1 23:44:04 flip slapd[9255]: daemon: epoll: listen=8 active_threads=0 tvp=zero Apr 1 23:44:04 flip slapd[9255]: daemon: epoll: listen=9 active_threads=0 tvp=zero Apr 1 23:44:04 flip slapd[9255]: daemon: epoll: listen=10 active_threads=0 tvp=zero Apr 1 23:44:04 flip slapd[9255]: daemon: epoll: listen=11 active_threads=0 tvp=zero Apr 1 23:44:04 flip slapd[9255]: daemon: activity on 1 descriptor Apr 1 23:44:04 flip slapd[9255]: daemon: activity on: Apr 1 23:44:04 flip slapd[9255]: 54r Apr 1 23:44:04 flip slapd[9255]: Apr 1 23:44:04 flip slapd[9255]: daemon: read active on 54 Apr 1 23:44:04 flip slapd[9255]: daemon: epoll: listen=8 active_threads=0 tvp=zero Apr 1 23:44:04 flip slapd[9255]: daemon: epoll: listen=9 active_threads=0 tvp=zero Apr 1 23:44:04 flip slapd[9255]: connection_get(54) Apr 1 23:44:04 flip slapd[9255]: daemon: epoll: listen=10 active_threads=0 tvp=zero Apr 1 23:44:04 flip slapd[9255]: connection_get(54): got connid=1378 Apr 1 23:44:04 flip slapd[9255]: connection_read(54): checking for input on id=1378 Apr 1 23:44:04 flip slapd[9255]: daemon: epoll: listen=11 active_threads=0 tvp=zero Apr 1 23:44:04 flip slapd[9255]: daemon: activity on 1 descriptor Apr 1 23:44:04 flip slapd[9255]: daemon: activity on: Apr 1 23:44:04 flip slapd[9255]: Apr 1 23:44:04 flip slapd[9255]: daemon: epoll: listen=8 active_threads=0 tvp=zero Apr 1 23:44:04 flip slapd[9255]: daemon: epoll: listen=9 active_threads=0 tvp=zero Apr 1 23:44:04 flip slapd[9255]: daemon: epoll: listen=10 active_threads=0 tvp=zero Apr 1 23:44:04 flip slapd[9255]: daemon: epoll: listen=11 active_threads=0 tvp=zero Apr 1 23:44:04 flip slapd[9255]: daemon: activity on 1 descriptor Apr 1 23:44:04 flip slapd[9255]: daemon: activity on: Apr 1 23:44:04 flip slapd[9255]: 54r Apr 1 23:44:04 flip slapd[9255]: Apr 1 23:44:04 flip slapd[9255]: daemon: read active on 54 Apr 1 23:44:04 flip slapd[9255]: daemon: epoll: listen=8 active_threads=0 tvp=zero Apr 1 23:44:04 flip slapd[9255]: daemon: epoll: listen=9 active_threads=0 tvp=zero Apr 1 23:44:04 flip slapd[9255]: daemon: epoll: listen=10 active_threads=0 tvp=zero Apr 1 23:44:04 flip slapd[9255]: daemon: epoll: listen=11 active_threads=0 tvp=zero Apr 1 23:44:04 flip slapd[9255]: connection_get(54) Apr 1 23:44:04 flip slapd[9255]: connection_get(54): got connid=1378 Apr 1 23:44:04 flip slapd[9255]: connection_read(54): checking for input on id=1378 Apr 1 23:44:04 flip slapd[9255]: connection_read(54): unable to get TLS client DN, error=49 id=1378 Apr 1 23:44:04 flip slapd[9255]: conn=1378 fd=54 TLS established tls_ssf=128 ssf=128 Apr 1 23:44:04 flip slapd[9255]: daemon: activity on 1 descriptor Apr 1 23:44:04 flip slapd[9255]: daemon: activity on: Apr 1 23:44:04 flip slapd[9255]: Apr 1 23:44:04 flip slapd[9255]: daemon: epoll: listen=8 active_threads=0 tvp=zero Apr 1 23:44:04 flip slapd[9255]: daemon: epoll: listen=9 active_threads=0 tvp=zero Apr 1 23:44:04 flip slapd[9255]: daemon: epoll: listen=10 active_threads=0 tvp=zero Apr 1 23:44:04 flip slapd[9255]: daemon: epoll: listen=11 active_threads=0 tvp=zero Apr 1 23:44:04 flip slapd[9255]: daemon: activity on 1 descriptor Apr 1 23:44:04 flip slapd[9255]: daemon: activity on: Apr 1 23:44:04 flip slapd[9255]: 54r Apr 1 23:44:04 flip slapd[9255]: Apr 1 23:44:04 flip slapd[9255]: daemon: read active on 54 Apr 1 23:44:04 flip slapd[9255]: daemon: epoll: listen=8 active_threads=0 tvp=zero Apr 1 23:44:04 flip slapd[9255]: daemon: epoll: listen=9 active_threads=0 tvp=zero Apr 1 23:44:04 flip slapd[9255]: daemon: epoll: listen=10 active_threads=0 tvp=zero Apr 1 23:44:04 flip slapd[9255]: daemon: epoll: listen=11 active_threads=0 tvp=zero Apr 1 23:44:04 flip slapd[9255]: connection_get(54) Apr 1 23:44:04 flip slapd[9255]: connection_get(54): got connid=1378 Apr 1 23:44:04 flip slapd[9255]: connection_read(54): checking for input on id=1378 Apr 1 23:44:04 flip slapd[9255]: op tag 0x60, time 1333338244 Apr 1 23:44:04 flip slapd[9255]: conn=1378 op=1 do_bind Apr 1 23:44:04 flip slapd[9255]: >>> dnPrettyNormal: <uid=dit_admin,ou=role_accounts,ou=accounts,dc=example,dc=net> Apr 1 23:44:04 flip slapd[9255]: <<< dnPrettyNormal: <uid=dit_admin,ou=role_accounts,ou=accounts,dc=example,dc=net>, <uid=dit_admin,ou=role_accounts,ou=accounts,dc=example,dc=net> Apr 1 23:44:04 flip slapd[9255]: conn=1378 op=1 BIND dn="uid=dit_admin,ou=role_accounts,ou=accounts,dc=example,dc=net" method=128 Apr 1 23:44:04 flip slapd[9255]: do_bind: version=3 dn="uid=dit_admin,ou=role_accounts,ou=accounts,dc=example,dc=net" method=128 Apr 1 23:44:04 flip slapd[9255]: ==> hdb_bind: dn: uid=dit_admin,ou=role_accounts,ou=accounts,dc=example,dc=net Apr 1 23:44:04 flip slapd[9255]: bdb_dn2entry("uid=dit_admin,ou=role_accounts,ou=accounts,dc=example,dc=net") Apr 1 23:44:04 flip slapd[9255]: => access_allowed: result not in cache (userPassword) Apr 1 23:44:04 flip slapd[9255]: => access_allowed: auth access to "uid=dit_admin,ou=role_accounts,ou=accounts,dc=example,dc=net" "userPassword" requested Apr 1 23:44:04 flip slapd[9255]: => acl_get: [1] attr userPassword Apr 1 23:44:04 flip slapd[9255]: => acl_mask: access to entry "uid=dit_admin,ou=role_accounts,ou=accounts,dc=example,dc=net", attr "userPassword" requested Apr 1 23:44:04 flip slapd[9255]: => acl_mask: to value by "", (=0) Apr 1 23:44:04 flip slapd[9255]: <= check a_dn_pat: anonymous Apr 1 23:44:04 flip slapd[9255]: <= acl_mask: [1] applying auth(=xd) (stop) Apr 1 23:44:04 flip slapd[9255]: <= acl_mask: [1] mask: auth(=xd) Apr 1 23:44:04 flip slapd[9255]: => slap_access_allowed: auth access granted by auth(=xd) Apr 1 23:44:04 flip slapd[9255]: => access_allowed: auth access granted by auth(=xd) Apr 1 23:44:04 flip slapd[9255]: conn=1378 op=1 BIND dn="uid=dit_admin,ou=role_accounts,ou=accounts,dc=example,dc=net" mech=SIMPLE ssf=0 Apr 1 23:44:04 flip slapd[9255]: do_bind: v3 bind: "uid=dit_admin,ou=role_accounts,ou=accounts,dc=example,dc=net" to "uid=dit_admin,ou=role_accounts,ou=accounts,dc=example,dc=net" Apr 1 23:44:04 flip slapd[9255]: send_ldap_result: conn=1378 op=1 p=3 Apr 1 23:44:04 flip slapd[9255]: send_ldap_result: err=0 matched="" text="" Apr 1 23:44:04 flip slapd[9255]: send_ldap_response: msgid=2 tag=97 err=0 Apr 1 23:44:04 flip slapd[9255]: daemon: activity on 1 descriptor Apr 1 23:44:04 flip slapd[9255]: daemon: activity on: Apr 1 23:44:04 flip slapd[9255]: Apr 1 23:44:04 flip slapd[9255]: daemon: epoll: listen=8 active_threads=0 tvp=zero Apr 1 23:44:04 flip slapd[9255]: daemon: epoll: listen=9 active_threads=0 tvp=zero Apr 1 23:44:04 flip slapd[9255]: daemon: epoll: listen=10 active_threads=0 tvp=zero Apr 1 23:44:04 flip slapd[9255]: daemon: epoll: listen=11 active_threads=0 tvp=zero Apr 1 23:44:04 flip slapd[9255]: daemon: activity on 1 descriptor Apr 1 23:44:04 flip slapd[9255]: daemon: activity on: Apr 1 23:44:04 flip slapd[9255]: 54r Apr 1 23:44:04 flip slapd[9255]: Apr 1 23:44:04 flip slapd[9255]: daemon: read active on 54 Apr 1 23:44:04 flip slapd[9255]: daemon: epoll: listen=8 active_threads=0 tvp=zero Apr 1 23:44:04 flip slapd[9255]: daemon: epoll: listen=9 active_threads=0 tvp=zero Apr 1 23:44:04 flip slapd[9255]: daemon: epoll: listen=10 active_threads=0 tvp=zero Apr 1 23:44:04 flip slapd[9255]: daemon: epoll: listen=11 active_threads=0 tvp=zero Apr 1 23:44:04 flip slapd[9255]: connection_get(54) Apr 1 23:44:04 flip slapd[9255]: conn=1378 op=1 RESULT tag=97 err=0 text= Apr 1 23:44:04 flip slapd[9255]: connection_get(54): got connid=1378 Apr 1 23:44:04 flip slapd[9255]: connection_read(54): checking for input on id=1378 Apr 1 23:44:04 flip slapd[9255]: op tag 0x68, time 1333338244 Apr 1 23:44:04 flip slapd[9255]: conn=1378 op=2 do_add Apr 1 23:44:04 flip slapd[9255]: conn=1378 op=2 do_add: dn (cn=test_group,ou=general,ou=groups,dc=example,dc=net) Apr 1 23:44:04 flip slapd[9255]: >>> dnPrettyNormal: <cn=test_group,ou=general,ou=groups,dc=example,dc=net> Apr 1 23:44:04 flip slapd[9255]: <<< dnPrettyNormal: <cn=test_group,ou=general,ou=groups,dc=example,dc=net>, <cn=test_group,ou=general,ou=groups,dc=example,dc=net> Apr 1 23:44:04 flip slapd[9255]: conn=1378 op=2 ADD dn="cn=test_group,ou=general,ou=groups,dc=example,dc=net" Apr 1 23:44:04 flip slapd[9255]: >>> dnPretty: <uid=dummy_default,ou=dummy_accounts,ou=other,ou=accounts,dc=example,dc=net> Apr 1 23:44:04 flip slapd[9255]: <<< dnPretty: <uid=dummy_default,ou=dummy_accounts,ou=other,ou=accounts,dc=example,dc=net> Apr 1 23:44:04 flip slapd[9255]: >>> dnNormalize: <uid=dummy_default,ou=dummy_accounts,ou=other,ou=accounts,dc=example,dc=net> Apr 1 23:44:04 flip slapd[9255]: <<< dnNormalize: <uid=dummy_default,ou=dummy_accounts,ou=other,ou=accounts,dc=example,dc=net> Apr 1 23:44:04 flip slapd[9255]: bdb_dn2entry("cn=test_group,ou=general,ou=groups,dc=example,dc=net") Apr 1 23:44:04 flip slapd[9255]: => hdb_dn2id("cn=test_group,ou=general,ou=groups,dc=example,dc=net") Apr 1 23:44:04 flip slapd[9255]: <= hdb_dn2id: get failed: DB_NOTFOUND: No matching key/data pair found (-30988) Apr 1 23:44:04 flip slapd[9255]: hdb_referrals: tag=104 target="cn=test_group,ou=general,ou=groups,dc=example,dc=net" matched="ou=general,ou=groups,dc=example,dc=net" Apr 1 23:44:04 flip slapd[9255]: ==> unique_add <cn=test_group,ou=general,ou=groups,dc=example,dc=net> Apr 1 23:44:04 flip slapd[9255]: ==> hdb_add: cn=test_group,ou=general,ou=groups,dc=example,dc=net Apr 1 23:44:04 flip slapd[9255]: oc_check_required entry (cn=test_group,ou=general,ou=groups,dc=example,dc=net), objectClass "groupOfNames" Apr 1 23:44:04 flip slapd[9255]: oc_check_allowed type "objectClass" Apr 1 23:44:04 flip slapd[9255]: oc_check_allowed type "description" Apr 1 23:44:04 flip slapd[9255]: oc_check_allowed type "cn" Apr 1 23:44:04 flip slapd[9255]: oc_check_allowed type "member" Apr 1 23:44:04 flip slapd[9255]: oc_check_allowed type "structuralObjectClass" Apr 1 23:44:04 flip slapd[9255]: slap_queue_csn: queing 0xb2fcd8ce 20120402034404.808333Z#000000#000#000000 Apr 1 23:44:04 flip slapd[9255]: bdb_dn2entry("cn=test_group,ou=general,ou=groups,dc=example,dc=net") Apr 1 23:44:04 flip slapd[9255]: => hdb_dn2id("cn=test_group,ou=general,ou=groups,dc=example,dc=net") Apr 1 23:44:04 flip slapd[9255]: <= hdb_dn2id: get failed: DB_NOTFOUND: No matching key/data pair found (-30988) Apr 1 23:44:04 flip slapd[9255]: => access_allowed: add access to "ou=general,ou=groups,dc=example,dc=net" "children" requested Apr 1 23:44:04 flip slapd[9255]: <= root access granted Apr 1 23:44:04 flip slapd[9255]: => access_allowed: add access granted by manage(=mwrscxd) Apr 1 23:44:04 flip slapd[9255]: => access_allowed: add access to "cn=test_group,ou=general,ou=groups,dc=example,dc=net" "entry" requested Apr 1 23:44:04 flip slapd[9255]: <= root access granted Apr 1 23:44:04 flip slapd[9255]: => access_allowed: add access granted by manage(=mwrscxd) Apr 1 23:44:04 flip slapd[9255]: => hdb_dn2id_add 0xe8: "cn=test_group,ou=general,ou=groups,dc=example,dc=net" Apr 1 23:44:04 flip slapd[9255]: <= hdb_dn2id_add 0xe8: 0 Apr 1 23:44:04 flip slapd[9255]: => index_entry_add( 232, "cn=test_group,ou=general,ou=groups,dc=example,dc=net" ) Apr 1 23:44:04 flip slapd[9255]: => key_change(ADD,e8) Apr 1 23:44:04 flip slapd[9255]: bdb_idl_insert_key: e8 [0096defd] Apr 1 23:44:04 flip slapd[9255]: <= key_change 0 Apr 1 23:44:04 flip slapd[9255]: => key_change(ADD,e8) Apr 1 23:44:04 flip slapd[9255]: bdb_idl_insert_key: e8 [c14a3e76] Apr 1 23:44:04 flip slapd[9255]: <= key_change 0 Apr 1 23:44:04 flip slapd[9255]: => key_change(ADD,e8) Apr 1 23:44:04 flip slapd[9255]: bdb_idl_insert_key: e8 [943e86da] Apr 1 23:44:04 flip slapd[9255]: <= key_change 0 Apr 1 23:44:04 flip slapd[9255]: => key_change(ADD,e8) Apr 1 23:44:04 flip slapd[9255]: bdb_idl_insert_key: e8 [c866ab14] Apr 1 23:44:04 flip slapd[9255]: <= key_change 0

consumer log entries:

Apr 1 23:44:04 exo slapd[8007]: daemon: activity on 1 descriptor Apr 1 23:44:04 exo slapd[8007]: daemon: activity on: Apr 1 23:44:04 exo slapd[8007]: 12r Apr 1 23:44:04 exo slapd[8007]: Apr 1 23:44:04 exo slapd[8007]: daemon: read active on 12 Apr 1 23:44:04 exo slapd[8007]: daemon: epoll: listen=8 active_threads=0 tvp=NULL Apr 1 23:44:04 exo slapd[8007]: daemon: epoll: listen=9 active_threads=0 tvp=NULL Apr 1 23:44:04 exo slapd[8007]: connection_get(12) Apr 1 23:44:04 exo slapd[8007]: connection_get(12): got connid=0 Apr 1 23:44:04 exo slapd[8007]: =>do_syncrepl rid=000 Apr 1 23:44:04 exo slapd[8007]: =>do_syncrep2 rid=000 Apr 1 23:44:04 exo slapd[8007]: do_syncrep2: rid=000 cookie=rid=000,csn=20120402034404.869559Z#000000#000#000000 Apr 1 23:44:04 exo slapd[8007]: >>> dnPrettyNormal: <uid=dummy_default,ou=dummy_accounts,ou=other,ou=accounts,dc=example,dc=net> Apr 1 23:44:04 exo slapd[8007]: <<< dnPrettyNormal: <uid=dummy_default,ou=dummy_accounts,ou=other,ou=accounts,dc=example,dc=net>, <uid=dummy_default,ou=dummy_accounts,ou=other,ou=accounts,dc=example,dc=net> Apr 1 23:44:04 exo slapd[8007]: slap_queue_csn: queing 0x7f6bd2694710 20120402034404.869559Z#000000#000#000000 Apr 1 23:44:04 exo slapd[8007]: >>> dnPretty: <cn=test_group,ou=general,ou=groups,dc=example,dc=net> Apr 1 23:44:04 exo slapd[8007]: <<< dnPretty: <cn=test_group,ou=general,ou=groups,dc=example,dc=net> Apr 1 23:44:04 exo slapd[8007]: >>> dnNormalize: <cn=test_group,ou=general,ou=groups,dc=example,dc=net> Apr 1 23:44:04 exo slapd[8007]: <<< dnNormalize: <cn=test_group,ou=general,ou=groups,dc=example,dc=net> Apr 1 23:44:04 exo slapd[8007]: >>> dnPretty: <uid=dit_admin,ou=role_accounts,ou=accounts,dc=example,dc=net> Apr 1 23:44:04 exo slapd[8007]: <<< dnPretty: <uid=dit_admin,ou=role_accounts,ou=accounts,dc=example,dc=net> Apr 1 23:44:04 exo slapd[8007]: >>> dnNormalize: <uid=dit_admin,ou=role_accounts,ou=accounts,dc=example,dc=net> Apr 1 23:44:04 exo slapd[8007]: <<< dnNormalize: <uid=dit_admin,ou=role_accounts,ou=accounts,dc=example,dc=net> Apr 1 23:44:04 exo slapd[8007]: => bdb_entry_get: ndn: "uid=dummy_default,ou=dummy_accounts,ou=other,ou=accounts,dc=example,dc=net" Apr 1 23:44:04 exo slapd[8007]: => bdb_entry_get: oc: "(null)", at: "(null)" Apr 1 23:44:04 exo slapd[8007]: bdb_dn2entry("uid=dummy_default,ou=dummy_accounts,ou=other,ou=accounts,dc=example,dc=net") Apr 1 23:44:04 exo slapd[8007]: => bdb_entry_get: found entry: "uid=dummy_default,ou=dummy_accounts,ou=other,ou=accounts,dc=example,dc=net" Apr 1 23:44:04 exo slapd[8007]: bdb_entry_get: rc=0 Apr 1 23:44:04 exo slapd[8007]: hdb_modify: uid=dummy_default,ou=dummy_accounts,ou=other,ou=accounts,dc=example,dc=net Apr 1 23:44:04 exo slapd[8007]: bdb_dn2entry("uid=dummy_default,ou=dummy_accounts,ou=other,ou=accounts,dc=example,dc=net") Apr 1 23:44:04 exo slapd[8007]: bdb_modify_internal: 0x0000001a: uid=dummy_default,ou=dummy_accounts,ou=other,ou=accounts,dc=example,dc=net Apr 1 23:44:04 exo slapd[8007]: <= acl_access_allowed: granted to database root Apr 1 23:44:04 exo slapd[8007]: bdb_modify_internal: add memberOf Apr 1 23:44:04 exo slapd[8007]: dnMatch 17#012#011"cn=dummy_default,ou=dummy_groups,ou=other,ou=groups,dc=example,dc=net"#012#011"cn=test_group,ou=general,ou=groups,dc=example,dc=net" Apr 1 23:44:04 exo slapd[8007]: dnMatch -19#012#011"cn=all_people,ou=general,ou=groups,dc=example,dc=net"#012#011"cn=test_group,ou=general,ou=groups,dc=example,dc=net" Apr 1 23:44:04 exo slapd[8007]: dnMatch 2#012#011"cn=docs,ou=flip,ou=servers,ou=groups,dc=example,dc=net"#012#011"cn=test_group,ou=general,ou=groups,dc=example,dc=net" Apr 1 23:44:04 exo slapd[8007]: dnMatch 5#012#011"cn=monitor,ou=flip,ou=servers,ou=groups,dc=example,dc=net"#012#011"cn=test_group,ou=general,ou=groups,dc=example,dc=net" Apr 1 23:44:04 exo slapd[8007]: dnMatch 5#012#011"cn=systems,ou=flip,ou=servers,ou=groups,dc=example,dc=net"#012#011"cn=test_group,ou=general,ou=groups,dc=example,dc=net" Apr 1 23:44:04 exo slapd[8007]: dnMatch 14#012#011"cn=mail_submitters-non_auth,ou=general,ou=groups,dc=example,dc=net"#012#011"cn=test_group,ou=general,ou=groups,dc=example,dc=net" Apr 1 23:44:04 exo slapd[8007]: bdb_modify_internal: replace modifiersName Apr 1 23:44:04 exo slapd[8007]: bdb_modify_internal: replace entryCSN Apr 1 23:44:04 exo slapd[8007]: bdb_modify_internal: replace modifyTimestamp Apr 1 23:44:04 exo slapd[8007]: oc_check_required entry (uid=dummy_default,ou=dummy_accounts,ou=other,ou=accounts,dc=example,dc=net), objectClass "inetOrgPerson" Apr 1 23:44:04 exo slapd[8007]: oc_check_allowed type "uid" Apr 1 23:44:04 exo slapd[8007]: oc_check_allowed type "objectClass" Apr 1 23:44:04 exo slapd[8007]: oc_check_allowed type "sn" Apr 1 23:44:04 exo slapd[8007]: oc_check_allowed type "cn" Apr 1 23:44:04 exo slapd[8007]: oc_check_allowed type "structuralObjectClass" Apr 1 23:44:04 exo slapd[8007]: oc_check_allowed type "entryUUID" Apr 1 23:44:04 exo slapd[8007]: oc_check_allowed type "creatorsName" Apr 1 23:44:04 exo slapd[8007]: oc_check_allowed type "createTimestamp" Apr 1 23:44:04 exo slapd[8007]: oc_check_allowed type "memberOf" Apr 1 23:44:04 exo slapd[8007]: oc_check_allowed type "modifiersName" Apr 1 23:44:04 exo slapd[8007]: oc_check_allowed type "entryCSN" Apr 1 23:44:04 exo slapd[8007]: oc_check_allowed type "modifyTimestamp" Apr 1 23:44:04 exo slapd[8007]: => key_change(DELETE,1a) Apr 1 23:44:04 exo slapd[8007]: bdb_idl_delete_key: 1a Apr 1 23:44:04 exo slapd[8007]: <= key_change 0 Apr 1 23:44:04 exo slapd[8007]: => key_change(ADD,1a) Apr 1 23:44:04 exo slapd[8007]: bdb_idl_insert_key: 1a [768b75dc] Apr 1 23:44:04 exo slapd[8007]: <= key_change 0 Apr 1 23:44:04 exo slapd[8007]: => key_change(ADD,1a) Apr 1 23:44:04 exo slapd[8007]: bdb_idl_insert_key: 1a [7f0c99d1] Apr 1 23:44:04 exo slapd[8007]: <= key_change 0 Apr 1 23:44:04 exo slapd[8007]: => key_change(ADD,1a) Apr 1 23:44:04 exo slapd[8007]: bdb_idl_insert_key: 1a [0f345f5f] Apr 1 23:44:04 exo slapd[8007]: <= key_change 0 Apr 1 23:44:04 exo slapd[8007]: => key_change(ADD,1a) Apr 1 23:44:04 exo slapd[8007]: bdb_idl_insert_key: 1a [86c8d479] Apr 1 23:44:04 exo slapd[8007]: <= key_change 0 Apr 1 23:44:04 exo slapd[8007]: => key_change(ADD,1a) Apr 1 23:44:04 exo slapd[8007]: bdb_idl_insert_key: 1a [da3d54f3] Apr 1 23:44:04 exo slapd[8007]: <= key_change 0 Apr 1 23:44:04 exo slapd[8007]: => key_change(ADD,1a) Apr 1 23:44:04 exo slapd[8007]: bdb_idl_insert_key: 1a [8d6b497f] Apr 1 23:44:04 exo slapd[8007]: <= key_change 0 Apr 1 23:44:04 exo slapd[8007]: => key_change(ADD,1a) Apr 1 23:44:04 exo slapd[8007]: bdb_idl_insert_key: 1a [144a6a9d] Apr 1 23:44:04 exo slapd[8007]: <= key_change 0 Apr 1 23:44:04 exo slapd[8007]: => key_change(ADD,1a) Apr 1 23:44:04 exo slapd[8007]: bdb_idl_insert_key: 1a Apr 1 23:44:04 exo slapd[8007]: <= key_change 0 Apr 1 23:44:04 exo slapd[8007]: => entry_encode(0x0000001a): Apr 1 23:44:04 exo slapd[8007]: <= entry_encode(0x0000001a): Apr 1 23:44:04 exo slapd[8007]: hdb_modify: updated id=0000001a dn="uid=dummy_default,ou=dummy_accounts,ou=other,ou=accounts,dc=example,dc=net" Apr 1 23:44:04 exo slapd[8007]: send_ldap_result: conn=-1 op=0 p=0 Apr 1 23:44:04 exo slapd[8007]: send_ldap_result: err=0 matched="" text="" Apr 1 23:44:04 exo slapd[8007]: slap_graduate_commit_csn: removing 0x7f6bd267ec10 20120402034404.869559Z#000000#000#000000 Apr 1 23:44:04 exo slapd[8007]: syncrepl_message_to_op: rid=000 be_modify uid=dummy_default,ou=dummy_accounts,ou=other,ou=accounts,dc=example,dc=net (0) Apr 1 23:44:04 exo slapd[8007]: slap_queue_csn: queing 0x7f6bd268f8c0 20120402034404.869559Z#000000#000#000000 Apr 1 23:44:04 exo slapd[8007]: => bdb_entry_get: ndn: "dc=example,dc=net" Apr 1 23:44:04 exo slapd[8007]: => bdb_entry_get: oc: "(null)", at: "(null)" Apr 1 23:44:04 exo slapd[8007]: bdb_dn2entry("dc=example,dc=net") Apr 1 23:44:04 exo slapd[8007]: => bdb_entry_get: found entry: "dc=example,dc=net" Apr 1 23:44:04 exo slapd[8007]: bdb_entry_get: rc=0 Apr 1 23:44:04 exo slapd[8007]: hdb_modify: dc=example,dc=net Apr 1 23:44:04 exo slapd[8007]: bdb_dn2entry("dc=example,dc=net") Apr 1 23:44:04 exo slapd[8007]: bdb_modify_internal: 0x00000001: dc=example,dc=net Apr 1 23:44:04 exo slapd[8007]: <= acl_access_allowed: granted to database root Apr 1 23:44:04 exo slapd[8007]: bdb_modify_internal: replace contextCSN Apr 1 23:44:04 exo slapd[8007]: oc_check_required entry (dc=example,dc=net), objectClass "organization" Apr 1 23:44:04 exo slapd[8007]: oc_check_required entry (dc=example,dc=net), objectClass "dcObject" Apr 1 23:44:04 exo slapd[8007]: oc_check_allowed type "dc" Apr 1 23:44:04 exo slapd[8007]: oc_check_allowed type "objectClass" Apr 1 23:44:04 exo slapd[8007]: oc_check_allowed type "o" Apr 1 23:44:04 exo slapd[8007]: oc_check_allowed type "structuralObjectClass" Apr 1 23:44:04 exo slapd[8007]: oc_check_allowed type "entryUUID" Apr 1 23:44:04 exo slapd[8007]: oc_check_allowed type "creatorsName" Apr 1 23:44:04 exo slapd[8007]: oc_check_allowed type "createTimestamp" Apr 1 23:44:04 exo slapd[8007]: oc_check_allowed type "l" Apr 1 23:44:04 exo slapd[8007]: oc_check_allowed type "st" Apr 1 23:44:04 exo slapd[8007]: oc_check_allowed type "postalCode" Apr 1 23:44:04 exo slapd[8007]: oc_check_allowed type "entryCSN" Apr 1 23:44:04 exo slapd[8007]: oc_check_allowed type "modifiersName" Apr 1 23:44:04 exo slapd[8007]: oc_check_allowed type "modifyTimestamp" Apr 1 23:44:04 exo slapd[8007]: oc_check_allowed type "contextCSN" Apr 1 23:44:04 exo slapd[8007]: => entry_encode(0x00000001): Apr 1 23:44:04 exo slapd[8007]: <= entry_encode(0x00000001): Apr 1 23:44:04 exo slapd[8007]: hdb_modify: updated id=00000001 dn="dc=example,dc=net" Apr 1 23:44:04 exo slapd[8007]: send_ldap_result: conn=-1 op=0 p=0 Apr 1 23:44:04 exo slapd[8007]: send_ldap_result: err=0 matched="" text="" Apr 1 23:44:04 exo slapd[8007]: slap_graduate_commit_csn: removing 0x7f6bd2674970 20120402034404.869559Z#000000#000#000000 Apr 1 23:44:04 exo slapd[8007]: daemon: activity on 1 descriptor Apr 1 23:44:04 exo slapd[8007]: daemon: activity on: Apr 1 23:44:04 exo slapd[8007]: Apr 1 23:44:04 exo slapd[8007]: daemon: epoll: listen=8 active_threads=0 tvp=NULL Apr 1 23:44:04 exo slapd[8007]: daemon: epoll: listen=9 active_threads=0 tvp=NULL