[Date Prev][Date Next] [Chronological] [Thread] [Top]

Autogroup strange behaviour



Title: Luca Scamoni
Hi,
    I'm using autogroup overlay (OpenLDAP 2.4.23, autogroup v. 1.2.2.11 but the behaviour was the same with 1.2.2.6) and I'm facing a strange situation.
Operations performed using openldap client tools work as expected. The same operations performed using a java client do not.
I've restricted the problematic operations to modifications of existing entries. Using attached slapd.conf and ldap.ldif it's quite simple to reproduce it.

Using openldap ldapmodify client:

cn=user2,ou=people,dc=example,dc=com
add: description
description: test

modifies the entry AND triggers autogroup modify operation on group cn=description adding user2 as a member of the group (see slapd.log.ok.add)

The same operation performed with JExplorer modifies the entry but does NOT triggers autogroup modification (see slapd.log.java.add)

I've compared the two logs and overlay related modifications are completely skipped in the java client test.
Anyone has an explanation?

Note: adding a new entry or deleting an existing one (if it matches any of the criteria in memberUrl) works even with Jexplorer.

thanks





--

Luca Scamoni

Gruppo Partners Associates
Tel. Milano +39 02 67380435 - Udine +39 0432 689815 - Roma +39 06 54832300
Fax Milano +39 02 67386214 - Udine +39 0432 570120 - Roma +39 06 91659273
Cell. +39 348 0471710
Email:
Luca.Scamoni@GruppoPA.it
Sito:
www.GruppoPA.it 


Prima di stampare, pensa all'ambiente ** Think about the environment before printing

dn: dc=example,dc=com
objectClass: dcObject
objectClass: organization
o: example.com
dc: example

dn: ou=people,dc=example,dc=com
objectClass: organizationalUnit
ou: people

dn: ou=groups,dc=example,dc=com
objectClass: organizationalUnit
ou: groups

dn: cn=autogroup,ou=groups,dc=example,dc=com
objectClass: groupOfURLs
cn: autogroup
memberURL: ldap:///ou=people,dc=example,dc=com??sub?(objectclass=person)
member: cn=user,ou=people,dc=example,dc=com
member: cn=user1,ou=people,dc=example,dc=com
member: cn=user2,ou=people,dc=example,dc=com

dn: cn=user,ou=people,dc=example,dc=com
objectClass: person
cn: user
sn: user

dn: cn=description,ou=groups,dc=example,dc=com
objectClass: groupOfURLs
cn: description
memberURL: ldap:///ou=people,dc=example,dc=com??sub?(description=*)
member: cn=user1,ou=people,dc=example,dc=com

dn: cn=user1,ou=people,dc=example,dc=com
objectClass: person
cn: user1
sn: user1
description: test

dn: cn=user2,ou=people,dc=example,dc=com
objectClass: person
cn: user2
sn: user2

include		/opt/ldap/etc/schema/core.schema
include		/opt/ldap/etc/schema/dyngroup.schema

pidfile		/opt/ldap/var/run/slapd.pid
argsfile	/opt/ldap/var/run/slapd.args

modulepath	/opt/ldap/sbin
moduleload	memberof.la
moduleload	autogroup.la

loglevel	-1
threads		4
tool-threads	1

access to dn.base="" by * read
access to dn.base="cn=Subschema" by * read

database	hdb
suffix		"dc=example,dc=com"
rootdn		"cn=Manager,dc=example,dc=com"
rootpw		secret

cachesize	1000
dncachesize	3000
idlcachesize	3000

checkpoint	10 5

overlay memberof

overlay autogroup
autogroup-attrset groupOfURLs memberURL member

directory	/opt/ldap/var/openldap-data

index	objectClass	eq
index	entryUUID,entryCSN	eq
Feb 13 15:20:35 allianz slapd[22304]: daemon: activity on 1 descriptor 
Feb 13 15:20:35 allianz slapd[22304]: daemon: activity on:
Feb 13 15:21:03 allianz slapd[22304]:  14r
Feb 13 15:21:03 allianz slapd[22304]:  
Feb 13 15:21:03 allianz slapd[22304]: daemon: read active on 14 
Feb 13 15:21:03 allianz slapd[22304]: daemon: epoll: listen=7 active_threads=0 tvp=zero 
Feb 13 15:21:03 allianz slapd[22304]: daemon: epoll: listen=8 active_threads=0 tvp=zero 
Feb 13 15:21:03 allianz slapd[22304]: connection_get(14) 
Feb 13 15:21:03 allianz slapd[22304]: connection_get(14): got connid=1003 
Feb 13 15:21:03 allianz slapd[22304]: connection_read(14): checking for input on id=1003 
Feb 13 15:21:03 allianz slapd[22304]: op tag 0x66, time 1297606863 
Feb 13 15:21:03 allianz slapd[22304]: conn=1003 op=1 do_modify 
Feb 13 15:21:03 allianz slapd[22304]: conn=1003 op=1 do_modify: dn (cn=user2,ou=people,dc=example,dc=com) 



Feb 13 15:21:03 allianz slapd[22304]: >>> dnPrettyNormal: <cn=user2,ou=people,dc=example,dc=com> 
Feb 13 15:21:03 allianz slapd[22304]: <<< dnPrettyNormal: <cn=user2,ou=people,dc=example,dc=com>, <cn=user2,ou=people,dc=example,dc=com> 
Feb 13 15:21:03 allianz slapd[22304]: conn=1003 op=1 modifications: 
Feb 13 15:21:03 allianz slapd[22304]: 	add: description 
Feb 13 15:21:03 allianz slapd[22304]: 		one value, length 5 
Feb 13 15:21:03 allianz slapd[22304]: conn=1003 op=1 MOD dn="cn=user2,ou=people,dc=example,dc=com" 
Feb 13 15:21:03 allianz slapd[22304]: conn=1003 op=1 MOD attr=description 

Feb 13 15:21:03 allianz slapd[22304]: bdb_dn2entry("cn=user2,ou=people,dc=example,dc=com") 
Feb 13 15:21:03 allianz slapd[22304]: ==> autogroup_modify_entry <cn=user2,ou=people,dc=example,dc=com> 
Feb 13 15:21:03 allianz slapd[22304]: => bdb_entry_get: ndn: "cn=user2,ou=people,dc=example,dc=com" 
Feb 13 15:21:03 allianz slapd[22304]: => bdb_entry_get: oc: "(null)", at: "(null)" 
Feb 13 15:21:03 allianz slapd[22304]: bdb_dn2entry("cn=user2,ou=people,dc=example,dc=com") 
Feb 13 15:21:03 allianz slapd[22304]: => bdb_entry_get: found entry: "cn=user2,ou=people,dc=example,dc=com" 
Feb 13 15:21:03 allianz slapd[22304]: bdb_entry_get: rc=0 
Feb 13 15:21:03 allianz slapd[22304]: => hdb_search 
Feb 13 15:21:03 allianz slapd[22304]: bdb_dn2entry("cn=user2,ou=people,dc=example,dc=com") 
Feb 13 15:21:03 allianz slapd[22304]: => access_allowed: search access to "cn=user2,ou=people,dc=example,dc=com" "entry" requested 
Feb 13 15:21:03 allianz slapd[22304]: <= root access granted 
Feb 13 15:21:03 allianz slapd[22304]: => access_allowed: search access granted by manage(=mwrscxd) 
Feb 13 15:21:03 allianz slapd[22304]: base_candidates: base: "cn=user2,ou=people,dc=example,dc=com" (0x00000008) 
Feb 13 15:21:03 allianz slapd[22304]: => test_filter 
Feb 13 15:21:03 allianz slapd[22304]:     EQUALITY 
Feb 13 15:21:03 allianz slapd[22304]: => access_allowed: search access to "cn=user2,ou=people,dc=example,dc=com" "objectClass" requested 
Feb 13 15:21:03 allianz slapd[22304]: <= root access granted 
Feb 13 15:21:03 allianz slapd[22304]: => access_allowed: search access granted by manage(=mwrscxd) 
Feb 13 15:21:03 allianz slapd[22304]: <= test_filter 5 
Feb 13 15:21:03 allianz slapd[22304]: hdb_search: 8 does not match filter 
Feb 13 15:21:03 allianz slapd[22304]: send_ldap_result: conn=1003 op=1 p=3 
Feb 13 15:21:03 allianz slapd[22304]: send_ldap_result: err=0 matched="" text="" 
Feb 13 15:21:03 allianz slapd[22304]: hdb_modify: cn=user2,ou=people,dc=example,dc=com 
Feb 13 15:21:03 allianz slapd[22304]: slap_queue_csn: queing 0x42d53290 20110213142103.518452Z#000000#000#000000 
Feb 13 15:21:03 allianz slapd[22304]: bdb_dn2entry("cn=user2,ou=people,dc=example,dc=com") 
Feb 13 15:21:03 allianz slapd[22304]: bdb_modify_internal: 0x00000008: cn=user2,ou=people,dc=example,dc=com 
Feb 13 15:21:03 allianz slapd[22304]: <= acl_access_allowed: granted to database root 
Feb 13 15:21:03 allianz slapd[22304]: bdb_modify_internal: add description 
Feb 13 15:21:03 allianz slapd[22304]: bdb_modify_internal: replace entryCSN 
Feb 13 15:21:03 allianz slapd[22304]: bdb_modify_internal: replace modifiersName 
Feb 13 15:21:03 allianz slapd[22304]: bdb_modify_internal: replace modifyTimestamp 
Feb 13 15:21:03 allianz slapd[22304]: oc_check_required entry (cn=user2,ou=people,dc=example,dc=com), objectClass "person" 
Feb 13 15:21:03 allianz slapd[22304]: oc_check_allowed type "cn" 
Feb 13 15:21:03 allianz slapd[22304]: oc_check_allowed type "objectClass" 
Feb 13 15:21:03 allianz slapd[22304]: oc_check_allowed type "sn" 
Feb 13 15:21:03 allianz slapd[22304]: oc_check_allowed type "structuralObjectClass" 
Feb 13 15:21:03 allianz slapd[22304]: oc_check_allowed type "entryUUID" 
Feb 13 15:21:03 allianz slapd[22304]: oc_check_allowed type "creatorsName" 
Feb 13 15:21:03 allianz slapd[22304]: oc_check_allowed type "createTimestamp" 
Feb 13 15:21:03 allianz slapd[22304]: oc_check_allowed type "description" 
Feb 13 15:21:03 allianz slapd[22304]: oc_check_allowed type "entryCSN" 
Feb 13 15:21:03 allianz slapd[22304]: oc_check_allowed type "modifiersName" 
Feb 13 15:21:03 allianz slapd[22304]: oc_check_allowed type "modifyTimestamp" 
Feb 13 15:21:03 allianz slapd[22304]: => key_change(DELETE,8) 
Feb 13 15:21:03 allianz slapd[22304]: bdb_idl_delete_key: 8  
Feb 13 15:21:03 allianz slapd[22304]: <= key_change 0 
Feb 13 15:21:03 allianz slapd[22304]: => key_change(ADD,8) 
Feb 13 15:21:03 allianz slapd[22304]: bdb_idl_insert_key: 8  
Feb 13 15:21:03 allianz slapd[22304]: <= key_change 0 
Feb 13 15:21:03 allianz slapd[22304]: => entry_encode(0x00000008):  
Feb 13 15:21:03 allianz slapd[22304]: <= entry_encode(0x00000008):  
Feb 13 15:21:03 allianz slapd[22304]: hdb_modify: updated id=00000008 dn="cn=user2,ou=people,dc=example,dc=com" 
Feb 13 15:21:03 allianz slapd[22304]: send_ldap_result: conn=1003 op=1 p=3 
Feb 13 15:21:03 allianz slapd[22304]: send_ldap_result: err=0 matched="" text="" 
Feb 13 15:21:03 allianz slapd[22304]: ==> autogroup_response MODIFY <cn=user2,ou=people,dc=example,dc=com> 
Feb 13 15:21:03 allianz slapd[22304]: => bdb_entry_get: ndn: "cn=user2,ou=people,dc=example,dc=com" 
Feb 13 15:21:03 allianz slapd[22304]: => bdb_entry_get: oc: "(null)", at: "(null)" 
Feb 13 15:21:03 allianz slapd[22304]: bdb_dn2entry("cn=user2,ou=people,dc=example,dc=com") 
Feb 13 15:21:03 allianz slapd[22304]: => bdb_entry_get: found entry: "cn=user2,ou=people,dc=example,dc=com" 
Feb 13 15:21:03 allianz slapd[22304]: bdb_entry_get: rc=0 
Feb 13 15:21:03 allianz slapd[22304]: => bdb_entry_get: ndn: "cn=autogroup,ou=groups,dc=example,dc=com" 
Feb 13 15:21:03 allianz slapd[22304]: => bdb_entry_get: oc: "(null)", at: "(null)" 
Feb 13 15:21:03 allianz slapd[22304]: bdb_dn2entry("cn=autogroup,ou=groups,dc=example,dc=com") 
Feb 13 15:21:03 allianz slapd[22304]: => bdb_entry_get: found entry: "cn=autogroup,ou=groups,dc=example,dc=com" 
Feb 13 15:21:03 allianz slapd[22304]: bdb_entry_get: rc=0 
Feb 13 15:21:03 allianz slapd[22304]: dnMatch -1 	"cn=user,ou=people,dc=example,dc=com" 	"cn=user2,ou=people,dc=example,dc=com" 
Feb 13 15:21:03 allianz slapd[22304]: dnMatch -1 	"cn=user1,ou=people,dc=example,dc=com" 	"cn=user2,ou=people,dc=example,dc=com" 
Feb 13 15:21:03 allianz slapd[22304]: dnMatch 0 	"cn=user2,ou=people,dc=example,dc=com" 	"cn=user2,ou=people,dc=example,dc=com" 
Feb 13 15:21:03 allianz slapd[22304]: => test_filter 
Feb 13 15:21:03 allianz slapd[22304]:     EQUALITY 
Feb 13 15:21:03 allianz slapd[22304]: => access_allowed: search access to "cn=user2,ou=people,dc=example,dc=com" "objectClass" requested 
Feb 13 15:21:03 allianz slapd[22304]: <= root access granted 
Feb 13 15:21:03 allianz slapd[22304]: => access_allowed: search access granted by manage(=mwrscxd) 
Feb 13 15:21:03 allianz slapd[22304]: <= test_filter 6 
Feb 13 15:21:03 allianz slapd[22304]: => bdb_entry_get: ndn: "cn=description,ou=groups,dc=example,dc=com" 
Feb 13 15:21:03 allianz slapd[22304]: => bdb_entry_get: oc: "(null)", at: "(null)" 
Feb 13 15:21:03 allianz slapd[22304]: bdb_dn2entry("cn=description,ou=groups,dc=example,dc=com") 
Feb 13 15:21:03 allianz slapd[22304]: => bdb_entry_get: found entry: "cn=description,ou=groups,dc=example,dc=com" 
Feb 13 15:21:03 allianz slapd[22304]: bdb_entry_get: rc=0 
Feb 13 15:21:03 allianz slapd[22304]: dnMatch -1 	"cn=user1,ou=people,dc=example,dc=com" 	"cn=user2,ou=people,dc=example,dc=com" 
Feb 13 15:21:03 allianz slapd[22304]: => test_filter 
Feb 13 15:21:03 allianz slapd[22304]:     PRESENT 
Feb 13 15:21:03 allianz slapd[22304]: => access_allowed: search access to "cn=user2,ou=people,dc=example,dc=com" "description" requested 
Feb 13 15:21:03 allianz slapd[22304]: <= root access granted 
Feb 13 15:21:03 allianz slapd[22304]: => access_allowed: search access granted by manage(=mwrscxd) 
Feb 13 15:21:03 allianz slapd[22304]: <= test_filter 6 
Feb 13 15:21:03 allianz slapd[22304]: ==> autogroup_add_member_to_group adding <cn=user2,ou=people,dc=example,dc=com> to <cn=description,ou=groups,dc=example,dc=com> 
Feb 13 15:21:03 allianz slapd[22304]: => hdb_search 
Feb 13 15:21:03 allianz slapd[22304]: bdb_dn2entry("cn=description,ou=groups,dc=example,dc=com") 
Feb 13 15:21:03 allianz slapd[22304]: => access_allowed: search access to "cn=description,ou=groups,dc=example,dc=com" "entry" requested 
Feb 13 15:21:03 allianz slapd[22304]: <= root access granted 
Feb 13 15:21:03 allianz slapd[22304]: => access_allowed: search access granted by manage(=mwrscxd) 
Feb 13 15:21:03 allianz slapd[22304]: base_candidates: base: "cn=description,ou=groups,dc=example,dc=com" (0x00000006) 
Feb 13 15:21:03 allianz slapd[22304]: => test_filter 
Feb 13 15:21:03 allianz slapd[22304]:     EQUALITY 
Feb 13 15:21:03 allianz slapd[22304]: => access_allowed: search access to "cn=description,ou=groups,dc=example,dc=com" "objectClass" requested 
Feb 13 15:21:03 allianz slapd[22304]: <= root access granted 
Feb 13 15:21:03 allianz slapd[22304]: => access_allowed: search access granted by manage(=mwrscxd) 
Feb 13 15:21:03 allianz slapd[22304]: <= test_filter 5 
Feb 13 15:21:03 allianz slapd[22304]: hdb_search: 6 does not match filter 
Feb 13 15:21:03 allianz slapd[22304]: send_ldap_result: conn=1003 op=1 p=3 
Feb 13 15:21:03 allianz slapd[22304]: send_ldap_result: err=0 matched="" text="" 
Feb 13 15:21:03 allianz slapd[22304]: hdb_modify: cn=description,ou=groups,dc=example,dc=com 
Feb 13 15:21:03 allianz slapd[22304]: bdb_dn2entry("cn=description,ou=groups,dc=example,dc=com") 
Feb 13 15:21:03 allianz slapd[22304]: bdb_modify_internal: 0x00000006: cn=description,ou=groups,dc=example,dc=com 
Feb 13 15:21:03 allianz slapd[22304]: <= acl_access_allowed: granted to database root 
Feb 13 15:21:03 allianz slapd[22304]: bdb_modify_internal: add member 
Feb 13 15:21:03 allianz slapd[22304]: dnMatch -1 	"cn=user1,ou=people,dc=example,dc=com" 	"cn=user2,ou=people,dc=example,dc=com" 
Feb 13 15:21:03 allianz slapd[22304]: bdb_modify_internal: replace entryCSN 
Feb 13 15:21:03 allianz slapd[22304]: bdb_modify_internal: replace modifiersName 
Feb 13 15:21:03 allianz slapd[22304]: bdb_modify_internal: replace modifyTimestamp 
Feb 13 15:21:03 allianz slapd[22304]: oc_check_required entry (cn=description,ou=groups,dc=example,dc=com), objectClass "groupOfURLs" 
Feb 13 15:21:03 allianz slapd[22304]: oc_check_allowed type "objectClass" 
Feb 13 15:21:03 allianz slapd[22304]: oc_check_allowed type "cn" 
Feb 13 15:21:03 allianz slapd[22304]: oc_check_allowed type "structuralObjectClass" 
Feb 13 15:21:03 allianz slapd[22304]: oc_check_allowed type "entryUUID" 
Feb 13 15:21:03 allianz slapd[22304]: oc_check_allowed type "creatorsName" 
Feb 13 15:21:03 allianz slapd[22304]: oc_check_allowed type "createTimestamp" 
Feb 13 15:21:03 allianz slapd[22304]: oc_check_allowed type "memberURL" 
Feb 13 15:21:03 allianz slapd[22304]: oc_check_allowed type "member" 
Feb 13 15:21:03 allianz slapd[22304]: oc_check_allowed type "entryCSN" 
Feb 13 15:21:03 allianz slapd[22304]: oc_check_allowed type "modifiersName" 
Feb 13 15:21:03 allianz slapd[22304]: oc_check_allowed type "modifyTimestamp" 
Feb 13 15:21:03 allianz slapd[22304]: => key_change(DELETE,6) 
Feb 13 15:21:03 allianz slapd[22304]: bdb_idl_delete_key: 6  
Feb 13 15:21:03 allianz slapd[22304]: <= key_change 0 
Feb 13 15:21:03 allianz slapd[22304]: => key_change(ADD,6) 
Feb 13 15:21:03 allianz slapd[22304]: bdb_idl_insert_key: 6  
Feb 13 15:21:03 allianz slapd[22304]: <= key_change 0 
Feb 13 15:21:03 allianz slapd[22304]: => entry_encode(0x00000006):  
Feb 13 15:21:03 allianz slapd[22304]: <= entry_encode(0x00000006):  
Feb 13 15:21:03 allianz slapd[22304]: hdb_modify: updated id=00000006 dn="cn=description,ou=groups,dc=example,dc=com" 
Feb 13 15:21:03 allianz slapd[22304]: send_ldap_result: conn=1003 op=1 p=3 
Feb 13 15:21:03 allianz slapd[22304]: send_ldap_result: err=0 matched="" text="" 
Feb 13 15:21:03 allianz slapd[22304]: slap_graduate_commit_csn: removing 0x507c4a0 20110213142103.518452Z#000000#000#000000 
Feb 13 15:21:03 allianz slapd[22304]: send_ldap_response: msgid=2 tag=103 err=0 
Feb 13 15:21:03 allianz slapd[22304]: conn=1003 op=1 RESULT tag=103 err=0 text= 
Feb 13 15:21:06 allianz slapd[22304]: daemon: activity on 1 descriptor 
Feb 13 15:21:06 allianz slapd[22304]: daemon: activity on:
Feb 13 15:21:06 allianz slapd[22304]:  14r
Feb 13 15:21:06 allianz slapd[22304]:  
Feb 13 15:21:06 allianz slapd[22304]: daemon: read active on 14 
Feb 13 15:21:06 allianz slapd[22304]: daemon: epoll: listen=7 active_threads=0 tvp=zero 
Feb 13 15:21:06 allianz slapd[22304]: daemon: epoll: listen=8 active_threads=0 tvp=zero 
Feb 13 15:21:06 allianz slapd[22304]: connection_get(14) 
Feb 13 15:21:06 allianz slapd[22304]: connection_get(14): got connid=1003 
Feb 13 15:21:06 allianz slapd[22304]: connection_read(14): checking for input on id=1003 
Feb 13 15:21:06 allianz slapd[22304]: op tag 0x42, time 1297606866 
Feb 13 15:21:06 allianz slapd[22304]: ber_get_next on fd 14 failed errno=0 (Success) 
Feb 13 15:21:06 allianz slapd[22304]: connection_read(14): input error=-2 id=1003, closing. 
Feb 13 15:21:06 allianz slapd[22304]: connection_closing: readying conn=1003 sd=14 for close 
Feb 13 15:21:06 allianz slapd[22304]: connection_close: deferring conn=1003 sd=14 
Feb 13 15:21:06 allianz slapd[22304]: daemon: activity on 1 descriptor 
Feb 13 15:21:06 allianz slapd[22304]: daemon: activity on:
Feb 13 15:21:06 allianz slapd[22304]:  
Feb 13 15:21:06 allianz slapd[22304]: conn=1003 op=2 do_unbind 
Feb 13 15:21:06 allianz slapd[22304]: conn=1003 op=2 UNBIND 
Feb 13 15:21:06 allianz slapd[22304]: daemon: epoll: listen=7 active_threads=0 tvp=zero 
Feb 13 15:21:06 allianz slapd[22304]: daemon: epoll: listen=8 active_threads=0 tvp=zero 
Feb 13 15:21:06 allianz slapd[22304]: connection_resched: attempting closing conn=1003 sd=14 
Feb 13 15:21:06 allianz slapd[22304]: connection_close: conn=1003 sd=14 
Feb 13 15:21:06 allianz slapd[22304]: daemon: removing 14 
Feb 13 15:21:06 allianz slapd[22304]: conn=1003 fd=14 closed 
Feb 13 15:21:15 allianz slapd[22304]: daemon: shutdown requested and initiated. 
Feb 13 15:21:15 allianz slapd[22304]: daemon: closing 7 
Feb 13 15:21:15 allianz slapd[22304]: daemon: closing 8 
Feb 13 15:21:15 allianz slapd[22304]: slapd shutdown: waiting for 0 operations/tasks to finish 
Feb 13 15:21:15 allianz slapd[22304]: slapd shutdown: initiated 
Feb 13 15:21:15 allianz slapd[22304]: ==> autogroup_db_close 
Feb 13 15:21:15 allianz slapd[22304]: ====> bdb_cache_release_all 
Feb 13 15:21:15 allianz slapd[22304]: slapd destroy: freeing system resources. 
Feb 13 15:21:15 allianz slapd[22304]: ==> autogroup_db_destroy 
Feb 13 15:21:15 allianz slapd[22304]: slapd stopped.