and once again: can not delete a user!

[Thorsten Schnebeck]

Am Sonntag 25 Juli 2010, 15:36:05 schrieb Alexander Gran:
> Am Sonntag 25 Juli 2010, 04:51:50 schrieb Thorsten Schnebeck:
> > And now I need help. Where is the code that handles the stuff after
> > cleaning up and then removing the ldap entry? It seems to be a kolabd
> > backend - but so far I did not find anything.
> 
> Did you switch on kolabd debug mode? It will than spam your log, but shuld
> be quite clear where it stops.
> 
> regards
> Alex

Hi!

maybe I'm blind but I can not find the missing step on the master

Bye

  Thorsten

#############
Delete external User
#############
replica-log:

replica: 127.0.0.1:9999
replica: my.slave.tld:636
time: 1280074301
dn: cn=ldaptest kolab,cn=external,dc=master,dc=tld
changetype: modify
replace: kolabDeleteflag
kolabDeleteflag: my.slave.tld
kolabDeleteflag: my.master.tld
-
replace: userPassword
userPassword:: xxx
-
replace: entryCSN
entryCSN: 20100725161141Z#000000#00#000000
-
replace: modifiersName
modifiersName: cn=manager,cn=internal,dc=master,dc=tld
-
replace: modifyTimestamp
modifyTimestamp: 20100725161141Z
-

replica: 127.0.0.1:9999
replica: my.slave.tld:636
time: 1280074310
dn: cn=ldaptest kolab,cn=external,dc=master,dc=tld
changetype: modify
delete: kolabDeleteflag
kolabDeleteflag: my.slave.tld
-
replace: entryCSN
entryCSN: 20100725161150Z#000000#00#000000
-
replace: modifiersName
modifiersName: cn=manager,cn=internal,dc=master,dc=tld
-
replace: modifyTimestamp
modifyTimestamp: 20100725161150Z


kolabd-Log on master:

Jul 25 18:11:44 master kolabd: SD Debug: Request modifyRequest received
Jul 25 18:11:44 master kolabd: SD Debug: Writing response
Jul 25 18:11:44 master kolabd: SD: Change detected w/ no pending LDAP 
messages; waiting a second...
Jul 25 18:11:45 master kolabd: SD: Change detected w/ no pending LDAP 
messages; reloading services if needed
Jul 25 18:11:45 master kolabd: L: Synchronising
Jul 25 18:11:45 master kolabd: Y: Connecting to local Cyrus admin interface
Jul 25 18:11:45 master kolabd: L: Synchronising `user' objects
Jul 25 18:11:45 master kolabd: L: Connecting to LDAP server `127.0.0.1:389'
Jul 25 18:11:45 master kolabd: L: Binding to 
`cn=manager,cn=internal,dc=master,dc=tld'
Jul 25 18:11:45 master kolabd: L: Synchronising `user' DN `dc=master,dc=tld'
Jul 25 18:11:45 master kolabd: L Debug: filter is (&(objectClass=inetOrgPerson)
(modifytimestamp>=20100725020714Z))
Jul 25 18:11:45 master kolabd: L Debug: Kolab::LDAP::createObject() called 
with obj uid field `mail' for obj type `user'
Jul 25 18:11:45 master kolabd: L Debug: Kolab::LDAP::createObject() called 
with obj uid field `mail' for obj type `user'
Jul 25 18:11:45 master kolabd: L: Finished synchronising `user' DN 
`dc=master,dc=tld'
Jul 25 18:11:45 master kolabd: L: Finished `user' object synchronisation
Jul 25 18:11:45 master kolabd: L: Synchronising `sf' objects
Jul 25 18:11:45 master kolabd: L: Connecting to LDAP server `127.0.0.1:389'
Jul 25 18:11:45 master kolabd: L: Binding to 
`cn=manager,cn=internal,dc=master,dc=tld'
Jul 25 18:11:45 master kolabd: L: Synchronising `sf' DN `dc=master,dc=tld'
Jul 25 18:11:45 master kolabd: L Debug: filter is 
(&(objectClass=kolabsharedfolder))
Jul 25 18:11:45 master kolabd: L: Finished synchronising `sf' DN 
`dc=master,dc=tld'
Jul 25 18:11:45 master kolabd: L: Finished `sf' object synchronisation
Jul 25 18:11:45 master kolabd: L: Synchronising `group' objects
Jul 25 18:11:45 master kolabd: L: Connecting to LDAP server `127.0.0.1:389'
Jul 25 18:11:45 master kolabd: L: Binding to 
`cn=manager,cn=internal,dc=master,dc=tld'
Jul 25 18:11:45 master kolabd: L: Synchronising `group' DN `dc=master,dc=tld'
Jul 25 18:11:45 master kolabd: L Debug: filter is 
(&(objectClass=kolabgroupofnames)(modifytimestamp>=20100725003241Z))
Jul 25 18:11:45 master kolabd: L Debug: Kolab::LDAP::createObject() called 
with obj uid field `' for obj type `group'
Jul 25 18:11:45 master kolabd: L: Finished synchronising `group' DN 
`dc=master,dc=tld'
Jul 25 18:11:45 master kolabd: L: Finished `group' object synchronisation
Jul 25 18:11:45 master kolabd: L: Synchronising mailboxes
Jul 25 18:11:45 master kolabd: L: Opening mailbox uid cache DB
Jul 25 18:11:45 master kolabd: L: Opening graveyard uid/timestamp cache DB
Jul 25 18:11:45 master kolabd: last message repeated 23 times
Jul 25 18:11:45 master kolabd: L: Gravekeeping (period = 10080 minutes)
Jul 25 18:11:45 master kolabd: L: Synchronising domains
Jul 25 18:11:45 master kolabd: L: Connecting to LDAP server `127.0.0.1:389'
Jul 25 18:11:45 master kolabd: L: Binding to 
`cn=manager,cn=internal,dc=master,dc=tld'
Jul 25 18:11:45 master kolabd: L Debug: Unable to locate old calendar user 
with DN `cn=calendar,cn=internal,dc=master,dc=tld'
Jul 25 18:11:45 master kolabd: L Debug: Calendar user for domain `master.tld' 
exists
Jul 25 18:11:45 master kolabd: L Debug: Calendar user for domain `4rd-
master.tld' exists
Jul 25 18:11:45 master kolabd: L Debug: Calendar user for domain 
`2nd.master.tld' exists
Jul 25 18:11:45 master kolabd: L Debug: Calendar user for domain `3rd-
master.tld' exists
Jul 25 18:11:45 master kolabd: L Debug: Calendar user for domain `slave.tld' 
exists
Jul 25 18:11:45 master kolabd: L: Finished synchronisation
Jul 25 18:11:46 master kolabd: SD: Running /kolab/sbin/kolabconf
Jul 25 18:11:51 master kolabd: SD: /kolab/sbin/kolabconf complete
Jul 25 18:11:51 master kolabd: SD: Waiting for LDAP updates
Jul 25 18:11:51 master kolabd: SD Debug: Reading ASN
Jul 25 18:11:54 master kolabd: SD Debug: Request modifyRequest received
Jul 25 18:11:54 master kolabd: SD Debug: Writing response
Jul 25 18:11:54 master kolabd: SD: Change detected w/ no pending LDAP 
messages; waiting a second...
Jul 25 18:11:55 master kolabd: SD: Change detected w/ no pending LDAP 
messages; reloading services if needed
Jul 25 18:11:55 master kolabd: L: Synchronising
Jul 25 18:11:55 master kolabd: Y: Connecting to local Cyrus admin interface
Jul 25 18:11:55 master kolabd: L: Synchronising `user' objects
Jul 25 18:11:55 master kolabd: L: Connecting to LDAP server `127.0.0.1:389'
Jul 25 18:11:55 master kolabd: L: Binding to 
`cn=manager,cn=internal,dc=master,dc=tld'
Jul 25 18:11:55 master kolabd: L: Synchronising `user' DN `dc=master,dc=tld'
Jul 25 18:11:55 master kolabd: L Debug: filter is (&(objectClass=inetOrgPerson)
(modifytimestamp>=20100725020714Z))
Jul 25 18:11:55 master kolabd: L Debug: Kolab::LDAP::createObject() called 
with obj uid field `mail' for obj type `user'
Jul 25 18:11:55 master kolabd: L Debug: Kolab::LDAP::createObject() called 
with obj uid field `mail' for obj type `user'
Jul 25 18:11:55 master kolabd: L: Finished synchronising `user' DN 
`dc=master,dc=tld'
Jul 25 18:11:55 master kolabd: L: Finished `user' object synchronisation
Jul 25 18:11:55 master kolabd: L: Synchronising `sf' objects
Jul 25 18:11:55 master kolabd: L: Connecting to LDAP server `127.0.0.1:389'
Jul 25 18:11:55 master kolabd: L: Binding to 
`cn=manager,cn=internal,dc=master,dc=tld'
Jul 25 18:11:55 master kolabd: L: Synchronising `sf' DN `dc=master,dc=tld'
Jul 25 18:11:55 master kolabd: L Debug: filter is 
(&(objectClass=kolabsharedfolder))
Jul 25 18:11:55 master kolabd: L: Finished synchronising `sf' DN 
`dc=master,dc=tld'
Jul 25 18:11:55 master kolabd: L: Finished `sf' object synchronisation
Jul 25 18:11:55 master kolabd: L: Synchronising `group' objects
Jul 25 18:11:55 master kolabd: L: Connecting to LDAP server `127.0.0.1:389'
Jul 25 18:11:55 master kolabd: L: Binding to 
`cn=manager,cn=internal,dc=master,dc=tld'
Jul 25 18:11:55 master kolabd: L: Synchronising `group' DN `dc=master,dc=tld'
Jul 25 18:11:55 master kolabd: L Debug: filter is 
(&(objectClass=kolabgroupofnames)(modifytimestamp>=20100725003241Z))
Jul 25 18:11:55 master kolabd: L Debug: Kolab::LDAP::createObject() called 
with obj uid field `' for obj type `group'
Jul 25 18:11:55 master kolabd: L: Finished synchronising `group' DN 
`dc=master,dc=tld'
Jul 25 18:11:55 master kolabd: L: Finished `group' object synchronisation
Jul 25 18:11:55 master kolabd: L: Synchronising mailboxes
Jul 25 18:11:55 master kolabd: L: Opening mailbox uid cache DB
Jul 25 18:11:55 master kolabd: L: Opening graveyard uid/timestamp cache DB
Jul 25 18:11:55 master kolabd: last message repeated 23 times
Jul 25 18:11:55 master kolabd: L: Gravekeeping (period = 10080 minutes)
Jul 25 18:11:55 master kolabd: L: Synchronising domains
Jul 25 18:11:55 master kolabd: L: Connecting to LDAP server `127.0.0.1:389'
Jul 25 18:11:55 master kolabd: L: Binding to 
`cn=manager,cn=internal,dc=master,dc=tld'
Jul 25 18:11:55 master kolabd: L Debug: Unable to locate old calendar user 
with DN `cn=calendar,cn=internal,dc=master,dc=tld'
Jul 25 18:11:55 master kolabd: L Debug: Calendar user for domain `master.tld' 
exists
Jul 25 18:11:55 master kolabd: L Debug: Calendar user for domain `4rd-
master.tld' exists
Jul 25 18:11:56 master kolabd: L Debug: Calendar user for domain 
`2nd.master.tld' exists
Jul 25 18:11:56 master kolabd: L Debug: Calendar user for domain `3rd-
master.tld' exists
Jul 25 18:11:56 master kolabd: L Debug: Calendar user for domain `slave.tld' 
exists
Jul 25 18:11:56 master kolabd: L: Finished synchronisation
Jul 25 18:11:56 master kolabd: SD: Running /kolab/sbin/kolabconf
Jul 25 18:12:00 master kolabd: SD: /kolab/sbin/kolabconf complete
Jul 25 18:12:00 master kolabd: SD: Waiting for LDAP updates
Jul 25 18:12:00 master kolabd: SD Debug: Reading ASN


and on the slave:
Jul 25 18:11:49 slave kolabd: SD: Incoming connection accepted, peer=127.0.0.1
Jul 25 18:11:49 slave kolabd: SD: Waiting for LDAP updates
Jul 25 18:11:49 slave kolabd: SD Debug: Reading ASN
Jul 25 18:11:49 slave kolabd: SD Debug: Request bindRequest received
Jul 25 18:11:49 slave kolabd: SD Debug: Writing response
Jul 25 18:11:49 slave kolabd: SD: Waiting for LDAP updates
Jul 25 18:11:49 slave kolabd: SD Debug: Reading ASN
Jul 25 18:11:49 slave kolabd: SD Debug: Request modifyRequest received
Jul 25 18:11:49 slave kolabd: SD Debug: Writing response
Jul 25 18:11:49 slave kolabd: SD: Change detected w/ no pending LDAP messages; 
waiting a second...
Jul 25 18:11:50 slave kolabd: SD: Change detected w/ no pending LDAP messages; 
reloading services if needed
Jul 25 18:11:50 slave kolabd: L: Synchronising
Jul 25 18:11:50 slave kolabd: Y: Connecting to local Cyrus admin interface
Jul 25 18:11:50 slave kolabd: L: Synchronising `user' objects
Jul 25 18:11:50 slave kolabd: L: Connecting to LDAP server `127.0.0.1:389'
Jul 25 18:11:50 slave kolabd: L: Binding to 
`cn=manager,cn=internal,dc=master,dc=tld'
Jul 25 18:11:50 slave kolabd: L: Synchronising `user' DN `dc=master,dc=tld'
Jul 25 18:11:50 slave kolabd: L: Opening mailbox uid cache DB
Jul 25 18:11:50 slave kolabd: L: Removing my.slave.tld from kolabdeleteflag in 
`cn=ldaptest kolab,cn=external,dc=master,dc=tld'
Jul 25 18:11:50 slave kolabd: L Debug: Deleted object not found in mboxcache, 
returning
Jul 25 18:11:50 slave kolabd: L Debug: filter is (&(objectClass=inetOrgPerson)
(modifytimestamp>=20100725020714Z))
Jul 25 18:11:50 slave kolabd: L Debug: Kolab::LDAP::createObject() called with 
obj uid field `mail' for obj type `user'
Jul 25 18:11:50 slave kolabd: L Debug: Kolab::LDAP::createObject() called with 
obj uid field `mail' for obj type `user'
Jul 25 18:11:50 slave kolabd: L: Finished synchronising `user' DN 
`dc=master,dc=tld'
Jul 25 18:11:50 slave kolabd: L: Finished `user' object synchronisation
Jul 25 18:11:50 slave kolabd: L: Synchronising `sf' objects
Jul 25 18:11:50 slave kolabd: L: Connecting to LDAP server `127.0.0.1:389'
Jul 25 18:11:50 slave kolabd: L: Binding to 
`cn=manager,cn=internal,dc=master,dc=tld'
Jul 25 18:11:50 slave kolabd: L: Synchronising `sf' DN `dc=master,dc=tld'
Jul 25 18:11:50 slave kolabd: L Debug: filter is 
(&(objectClass=kolabsharedfolder))
Jul 25 18:11:50 slave kolabd: L: Finished synchronising `sf' DN 
`dc=master,dc=tld'
Jul 25 18:11:50 slave kolabd: L: Finished `sf' object synchronisation
Jul 25 18:11:50 slave kolabd: L: Synchronising `group' objects
Jul 25 18:11:50 slave kolabd: L: Connecting to LDAP server `127.0.0.1:389'
Jul 25 18:11:50 slave kolabd: L: Binding to 
`cn=manager,cn=internal,dc=master,dc=tld'
Jul 25 18:11:50 slave kolabd: L: Synchronising `group' DN `dc=master,dc=tld'
Jul 25 18:11:50 slave kolabd: L Debug: filter is 
(&(objectClass=kolabgroupofnames)(modifytimestamp>=20100725003241Z))
Jul 25 18:11:50 slave kolabd: L Debug: Kolab::LDAP::createObject() called with 
obj uid field `' for obj type `group'
Jul 25 18:11:50 slave kolabd: L: Finished synchronising `group' DN 
`dc=master,dc=tld'
Jul 25 18:11:50 slave kolabd: L: Finished `group' object synchronisation
Jul 25 18:11:50 slave kolabd: L: Synchronising mailboxes
Jul 25 18:11:50 slave kolabd: L: Opening mailbox uid cache DB
Jul 25 18:11:50 slave kolabd: L: Opening graveyard uid/timestamp cache DB
Jul 25 18:11:51 slave kolabd: last message repeated 23 times
Jul 25 18:11:51 slave kolabd: L: Gravekeeping (period = 10080 minutes)
Jul 25 18:11:51 slave kolabd: L: Synchronising domains
Jul 25 18:11:51 slave kolabd: L: Connecting to LDAP server `127.0.0.1:389'
Jul 25 18:11:51 slave kolabd: L: Binding to 
`cn=manager,cn=internal,dc=master,dc=tld'
Jul 25 18:11:51 slave kolabd: L Debug: Unable to locate old calendar user with 
DN `cn=calendar,cn=internal,dc=master,dc=tld'
Jul 25 18:11:51 slave kolabd: L Debug: Calendar user for domain `master.tld' 
exists
Jul 25 18:11:51 slave kolabd: L Debug: Calendar user for domain `4rd-
master.tld' exists
Jul 25 18:11:51 slave kolabd: L Debug: Calendar user for domain 
`2nd.master.tld' exists
Jul 25 18:11:51 slave kolabd: L Debug: Calendar user for domain `3rd-
master.tld' exists
Jul 25 18:11:51 slave kolabd: L Debug: Calendar user for domain `slave.tld' 
exists
Jul 25 18:11:51 slave kolabd: L: Finished synchronisation
Jul 25 18:11:51 slave kolabd: SD: Running /kolab/sbin/kolabconf
Jul 25 18:11:53 slave kolabd: SD: /kolab/sbin/kolabconf complete
Jul 25 18:11:53 slave kolabd: SD: Waiting for LDAP updates
Jul 25 18:11:53 slave kolabd: SD Debug: Reading ASN
Jul 25 18:11:54 slave kolabd: SD Debug: Reading ASN
Jul 25 18:11:54 slave kolabd: SD Debug: Connection closed
Jul 25 18:11:54 slave kolabd: SD Debug: Request unbindRequest received
Jul 25 18:12:56 slave kolabd: SD: Incoming connection accepted, peer=127.0.0.1
Jul 25 18:12:56 slave kolabd: SD: Waiting for LDAP updates
Jul 25 18:12:56 slave kolabd: SD Debug: Reading ASN
Jul 25 18:12:56 slave kolabd: SD Debug: Request bindRequest received
Jul 25 18:12:56 slave kolabd: SD Debug: Writing response
Jul 25 18:12:56 slave kolabd: SD: Waiting for LDAP updates
Jul 25 18:12:56 slave kolabd: SD Debug: Reading ASN
Jul 25 18:12:56 slave kolabd: SD Debug: Request modifyRequest received
Jul 25 18:12:56 slave kolabd: SD Debug: Writing response
Jul 25 18:12:56 slave kolabd: SD: Change detected w/ no pending LDAP messages; 
waiting a second...
Jul 25 18:12:57 slave kolabd: SD: Change detected w/ no pending LDAP messages; 
reloading services if needed
Jul 25 18:12:57 slave kolabd: L: Synchronising
Jul 25 18:12:57 slave kolabd: Y: Connecting to local Cyrus admin interface
Jul 25 18:12:57 slave kolabd: L: Synchronising `user' objects
Jul 25 18:12:57 slave kolabd: L: Connecting to LDAP server `127.0.0.1:389'
Jul 25 18:12:57 slave kolabd: L: Binding to 
`cn=manager,cn=internal,dc=master,dc=tld'
Jul 25 18:12:57 slave kolabd: L: Synchronising `user' DN `dc=master,dc=tld'
Jul 25 18:12:57 slave kolabd: L Debug: filter is (&(objectClass=inetOrgPerson)
(modifytimestamp>=20100725020714Z))
Jul 25 18:12:57 slave kolabd: L Debug: Kolab::LDAP::createObject() called with 
obj uid field `mail' for obj type `user'
Jul 25 18:12:57 slave kolabd: L Debug: Kolab::LDAP::createObject() called with 
obj uid field `mail' for obj type `user'
Jul 25 18:12:57 slave kolabd: L: Finished synchronising `user' DN 
`dc=master,dc=tld'
Jul 25 18:12:57 slave kolabd: L: Finished `user' object synchronisation
Jul 25 18:12:57 slave kolabd: L: Synchronising `sf' objects
Jul 25 18:12:57 slave kolabd: L: Connecting to LDAP server `127.0.0.1:389'
Jul 25 18:12:57 slave kolabd: L: Binding to 
`cn=manager,cn=internal,dc=master,dc=tld'
Jul 25 18:12:57 slave kolabd: L: Synchronising `sf' DN `dc=master,dc=tld'
Jul 25 18:12:57 slave kolabd: L Debug: filter is 
(&(objectClass=kolabsharedfolder))
Jul 25 18:12:57 slave kolabd: L: Finished synchronising `sf' DN 
`dc=master,dc=tld'
Jul 25 18:12:57 slave kolabd: L: Finished `sf' object synchronisation
Jul 25 18:12:57 slave kolabd: L: Synchronising `group' objects
Jul 25 18:12:57 slave kolabd: L: Connecting to LDAP server `127.0.0.1:389'
Jul 25 18:12:57 slave kolabd: L: Binding to 
`cn=manager,cn=internal,dc=master,dc=tld'
Jul 25 18:12:57 slave kolabd: L: Synchronising `group' DN `dc=master,dc=tld'
Jul 25 18:12:57 slave kolabd: L Debug: filter is 
(&(objectClass=kolabgroupofnames)(modifytimestamp>=20100725003241Z))
Jul 25 18:12:57 slave kolabd: L Debug: Kolab::LDAP::createObject() called with 
obj uid field `' for obj type `group'
Jul 25 18:12:57 slave kolabd: L: Finished synchronising `group' DN 
`dc=master,dc=tld'
Jul 25 18:12:57 slave kolabd: L: Finished `group' object synchronisation
Jul 25 18:12:57 slave kolabd: L: Synchronising mailboxes
Jul 25 18:12:57 slave kolabd: L: Opening mailbox uid cache DB
Jul 25 18:12:57 slave kolabd: L: Opening graveyard uid/timestamp cache DB
Jul 25 18:12:58 slave kolabd: last message repeated 23 times
Jul 25 18:12:58 slave kolabd: L: Gravekeeping (period = 10080 minutes)
Jul 25 18:12:58 slave kolabd: L: Synchronising domains
Jul 25 18:12:58 slave kolabd: L: Connecting to LDAP server `127.0.0.1:389'
Jul 25 18:12:58 slave kolabd: L: Binding to 
`cn=manager,cn=internal,dc=master,dc=tld'
Jul 25 18:12:58 slave kolabd: L Debug: Unable to locate old calendar user with 
DN `cn=calendar,cn=internal,dc=master,dc=tld'
Jul 25 18:12:58 slave kolabd: L Debug: Calendar user for domain `master.tld' 
exists
Jul 25 18:12:58 slave kolabd: L Debug: Calendar user for domain `4rd-
master.tld' exists
Jul 25 18:12:58 slave kolabd: L Debug: Calendar user for domain 
`2nd.master.tld' exists
Jul 25 18:12:58 slave kolabd: L Debug: Calendar user for domain `3rd-
master.tld' exists
Jul 25 18:12:58 slave kolabd: L Debug: Calendar user for domain `slave.tld' 
exists
Jul 25 18:12:58 slave kolabd: L: Finished synchronisation
Jul 25 18:12:58 slave kolabd: SD: Running /kolab/sbin/kolabconf
Jul 25 18:13:00 slave kolabd: SD: /kolab/sbin/kolabconf complete
Jul 25 18:13:00 slave kolabd: SD: Waiting for LDAP updates
Jul 25 18:13:00 slave kolabd: SD Debug: Reading ASN
Jul 25 18:13:01 slave kolabd: SD Debug: Reading ASN
Jul 25 18:13:01 slave kolabd: SD Debug: Connection closed
Jul 25 18:13:01 slave kolabd: SD Debug: Request unbindRequest received