[Date Prev][Date Next] [Chronological] [Thread] [Top]
groups added to provider not replicating to consumer

To: openldap-technical@openldap.org
Subject: groups added to provider not replicating to consumer
From: btb@bitrate.net
Date: Mon, 2 Apr 2012 00:00:29 -0400
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
Follow-Ups:
- Re: groups added to provider not replicating to consumer
  - From: btb <btb@bitrate.net>
- Re: groups added to provider not replicating to consumer
  - From: Quanah Gibson-Mount <quanah@zimbra.com>
Prev by Date: RE: problem with ldap backend
Next by Date: LDAP transactions
Index(es):
- Chronological
- Thread