Bug 32263 - sync ucs to s4 should skipp creation of objects missing in UDM
sync ucs to s4 should skipp creation of objects missing in UDM
Status: CLOSED FIXED
Product: UCS
Classification: Unclassified
Component: S4 Connector
UCS 3.2
Other Linux
: P5 normal (vote)
: UCS 3.2-2-errata
Assigned To: Stefan Gohmann
Arvid Requate
:
Depends on:
Blocks: 41906 40813 41756 41864
  Show dependency treegraph
 
Reported: 2013-08-19 17:45 CEST by Arvid Requate
Modified: 2016-08-03 16:05 CEST (History)
3 users (show)

See Also:
What kind of report is it?: ---
What type of bug is this?: ---
Who will be affected by this bug?: ---
How will those affected feel about the bug?: ---
User Pain:
Enterprise Customer affected?:
School Customer affected?:
ISV affected?:
Waiting Support:
Ticket number:
Bug group (optional): Further conceptual development
Max CVSS v3 score:


Attachments
connector-s4.log (59.46 KB, text/plain)
2013-08-19 17:45 CEST, Arvid Requate
Details
transaction log (61.28 KB, text/plain)
2013-08-19 17:45 CEST, Arvid Requate
Details
backup2master.log with set -x (128.51 KB, text/plain)
2013-08-19 17:47 CEST, Arvid Requate
Details
failed jenkins test connector-s4.log (3.79 MB, text/plain)
2014-07-13 12:27 CEST, Stefan Gohmann
Details
bug32263_qa1.patch (724 bytes, patch)
2014-07-21 14:35 CEST, Arvid Requate
Details | Diff
UCS_deleted_plain_GUID.patch (1.49 KB, patch)
2014-07-21 20:34 CEST, Arvid Requate
Details | Diff

Note You need to log in before you can comment on or make changes to this bug.
Description Arvid Requate univentionstaff 2013-08-19 17:45:00 CEST
Created attachment 5378 [details]
connector-s4.log

In a backup2master scenario the attached behaviour of the univention-s4-connector was observed, where an object is created by the S4 Connector which was deleted before both in UDM and Samba4. The S4 Connector should maybe better not attempt to create such an object? In this case it resulted in a reject (for some reason) and later led to the resurrection of the deleted object (in OpenLDAP, not in Samba4, which is not optimal either).
Comment 1 Arvid Requate univentionstaff 2013-08-19 17:45:31 CEST
Created attachment 5379 [details]
transaction log
Comment 2 Arvid Requate univentionstaff 2013-08-19 17:47:31 CEST
Created attachment 5380 [details]
backup2master.log  with set -x

For completeness, maybe this is also helpful. Incidentally I was debugging the univention-backup2master code.
Comment 3 Stefan Gohmann univentionstaff 2013-08-27 09:37:52 CEST
One way could be to save the objectGUID and entryUUID of a deleted object in the local database.
Comment 4 Stefan Gohmann univentionstaff 2013-11-30 18:52:28 CET
Yes, I think the connector should check again if the object still exists in UCS. Otherwise the object should not be created.
Comment 5 Stefan Gohmann univentionstaff 2014-04-11 11:56:18 CEST
I've created two test cases for this issue:
 * 52_s4connector/022_concurrent_deletion_in_ucs
 * 52_s4connector/023_concurrent_deletion_in_ad
Comment 6 Stefan Gohmann univentionstaff 2014-04-18 21:12:48 CEST
I've added a cache with the deleted objects in UCS (r49465):

root@master211:~# sqlite3 /etc/univention/connector/s4internal.sqlite "select * from 'UCS deleted'"   
bd210a2e-2707-1033-9b3a-cb9e79e9952e|bxEEeB/Cmn9Gwq1EOX7CiTTDgFY=

08512388-270a-1033-9bfa-cb9e79e9952e|w47CvjPDuMKKLMOtQcK2QlZHw7DDtQtl

The first value is the UCS entryUUID, the second value is the objectGUUID of the S4 object. When an object should be created or modified in S4, the cache is rechecked. If the entryUUID was already deleted, the object is not recreated in S4.

Waiting for test results.
Comment 7 Stefan Gohmann univentionstaff 2014-04-22 08:34:41 CEST
We have still a small gap in which the object could be synced back. But I don't know if it happened. I was unable to write a test case for it in a reasonable amount time.

The original issue should be fixed.

Commit: r49465
YAML: r49472

Test Cases:
  * 52_s4connector/022_concurrent_deletion_in_ucs
  * 52_s4connector/023_concurrent_deletion_in_ad
Comment 8 Stefan Gohmann univentionstaff 2014-05-06 14:38:08 CEST
Moved to UCS 3.2-2-errata. Bug #33621 contains the current patch status.
Comment 9 Stefan Gohmann univentionstaff 2014-07-07 08:31:37 CEST
Patches have been added to UCS 3.2-2-errata.
Comment 10 Stefan Gohmann univentionstaff 2014-07-13 12:27:26 CEST
Created attachment 5991 [details]
failed jenkins test connector-s4.log

The test case failed last night:

http://jenkins.knut.univention.de:8080/job/UCS%203.2-2%20Autotest%20MultiEnv/SambaVersion=s4,Systemrolle=master/78/testReport/junit/52_s4connector/023_concurrent_deletion_in_ad/test/

I've attached the connector log from this case.
Comment 11 Stefan Gohmann univentionstaff 2014-07-13 13:04:06 CEST
(In reply to Stefan Gohmann from comment #10)
> Created attachment 5991 [details]
> failed jenkins test connector-s4.log
> 
> The test case failed last night:
> 
> http://jenkins.knut.univention.de:8080/job/UCS%203.2-2%20Autotest%20MultiEnv/
> SambaVersion=s4,Systemrolle=master/78/testReport/junit/52_s4connector/
> 023_concurrent_deletion_in_ad/test/
> 
> I've attached the connector log from this case.

This is a strange situation. The users and the group were created in AD. While the first user was synced back the group was deleted in AD. Thus the users were added in UCS but the post modify functions failed because the group did not exist.

The group was rejected while the group members did not exist at the sync time.

After that the created objects are synced back from UCS to AD. We don't have a list of deleted objects from AD.
Comment 12 Stefan Gohmann univentionstaff 2014-07-13 13:09:00 CEST
> This is a strange situation. The users and the group were created in AD.
> While the first user was synced back the group was deleted in AD. Thus the
> users were added in UCS but the post modify functions failed because the
> group did not exist.
> 
> The group was rejected while the group members did not exist at the sync
> time.
> 
> After that the created objects are synced back from UCS to AD. We don't have
> a list of deleted objects from AD.

I've created a new bug report for this case: Bug #35345
Comment 13 Stefan Gohmann univentionstaff 2014-07-15 11:08:14 CEST
(In reply to Stefan Gohmann from comment #7)
> We have still a small gap in which the object could be synced back. But I
> don't know if it happened. I was unable to write a test case for it in a
> reasonable amount time.

Dmitry found a similar issue:

14.07.2014 14:11:04,130 LDAP        (PROCESS): sync from ucs: [          user] [       add] cn=v39y89nuku,cn=users,dc=autotest091,dc=local
14.07.2014 14:11:04,284 LDAP        (PROCESS): password_sync_ucs_to_s4: The UCS object (uid=v39y89nuku,cn=users,dc=autotest091,dc=local) was not found. The object was removed.
14.07.2014 14:11:04,291 LDAP        (PROCESS): primary_group_sync_from_ucs: The UCS object (uid=v39y89nuku,cn=users,dc=autotest091,dc=local) was not found. The object was removed.
14.07.2014 14:11:04,326 LDAP        (WARNING): sync failed, saved as rejected
        /var/lib/univention-connector/s4/1405361456.577944
14.07.2014 14:11:04,327 LDAP        (WARNING): Traceback (most recent call last):
  File "/usr/lib/pymodules/python2.6/univention/s4connector/__init__.py", line 778, in __sync_file_from_ucs
    or (not old_dn and not self.sync_from_ucs(key, object, premapped_ucs_dn, old_dn, old, new))):
  File "/usr/lib/pymodules/python2.6/univention/s4connector/s4/__init__.py", line 2355, in sync_from_ucs
    f(self, property_type, object)
  File "/usr/lib/pymodules/python2.6/univention/s4connector/s4/__init__.py", line 81, in disable_user_from_ucs
    return s4connector.disable_user_from_ucs(key, object)
  File "/usr/lib/pymodules/python2.6/univention/s4connector/s4/__init__.py", line 1903, in disable_user_from_ucs
    ucs_admin_object.open()
  File "/usr/lib/pymodules/python2.6/univention/admin/handlers/users/user.py", line 1453, in open
    self['primaryGroup']=None
  File "/usr/lib/pymodules/python2.6/univention/admin/handlers/__init__.py", line 229, in __setitem__
    raise univention.admin.uexceptions.valueRequired, _('The property %s is required') % self.descriptions[key].short_description
valueRequired: The property Primary group is required


The sync of the object was successful, the post modify functions failed. But the object is now in S4.

A little bit later:

14.07.2014 14:11:04,582 LDAP        (PROCESS): sync from ucs: [          user] [    delete] CN=v39y89nuku,cn=users,dc=autotest091,dc=local

But the object is still rejected and the connector tries to sync it:
14.07.2014 14:14:29,783 LDAP        (PROCESS): sync from ucs: [          user] [       add] cn=v39y89nuku,cn=users,dc=autotest091,dc=local
14.07.2014 14:14:29,987 LDAP        (PROCESS): password_sync_ucs_to_s4: The UCS object (uid=v39y89nuku,cn=users,dc=autotest091,dc=local) was not found. The object was removed.
14.07.2014 14:14:30,2 LDAP        (PROCESS): primary_group_sync_from_ucs: The UCS object (uid=v39y89nuku,cn=users,dc=autotest091,dc=local) was not found. The object was removed.
14.07.2014 14:14:30,40 LDAP        (WARNING): sync failed, saved as rejected
        /var/lib/univention-connector/s4/1405361456.577944
14.07.2014 14:14:30,40 LDAP        (WARNING): Traceback (most recent call last):
  File "/usr/lib/pymodules/python2.6/univention/s4connector/__init__.py", line 778, in __sync_file_from_ucs
    or (not old_dn and not self.sync_from_ucs(key, object, premapped_ucs_dn, old_dn, old, new))):
  File "/usr/lib/pymodules/python2.6/univention/s4connector/s4/__init__.py", line 2355, in sync_from_ucs
    f(self, property_type, object)
  File "/usr/lib/pymodules/python2.6/univention/s4connector/s4/__init__.py", line 81, in disable_user_from_ucs
    return s4connector.disable_user_from_ucs(key, object)
  File "/usr/lib/pymodules/python2.6/univention/s4connector/s4/__init__.py", line 1903, in disable_user_from_ucs
    ucs_admin_object.open()
  File "/usr/lib/pymodules/python2.6/univention/admin/handlers/users/user.py", line 1453, in open
    self['primaryGroup']=None
  File "/usr/lib/pymodules/python2.6/univention/admin/handlers/__init__.py", line 229, in __setitem__
    raise univention.admin.uexceptions.valueRequired, _('The property %s is required') % self.descriptions[key].short_description
valueRequired: The property Primary group is required

And then the object comes back as a new object:

14.07.2014 14:15:18,68 LDAP        (PROCESS): sync to ucs:   [          user] [       add] uid=v39y89nuku,cn=users,dc=autotest091,dc=local
Comment 14 Stefan Gohmann univentionstaff 2014-07-16 16:33:37 CEST
The test case has been adjusted: r51883

The connector now also adds the entryUUID to the deleted cache if the object is removed in S4: r51884
Comment 15 Arvid Requate univentionstaff 2014-07-21 14:35:03 CEST
Created attachment 6009 [details]
bug32263_qa1.patch

For consistency we should probably update the cache after the actual operation. In the sync_to_ucs it's done this way, this patch fixes the sync_to_s4 case as well.
Comment 16 Arvid Requate univentionstaff 2014-07-21 20:34:01 CEST
Created attachment 6014 [details]
UCS_deleted_plain_GUID.patch

This patch writes the objectGUID as a plain string to the "UCS deleted" table, not base64 encoded, improves readability.
Comment 17 Stefan Gohmann univentionstaff 2014-07-22 07:01:34 CEST
(In reply to Arvid Requate from comment #15)
> Created attachment 6009 [details]
> bug32263_qa1.patch
> 
> For consistency we should probably update the cache after the actual
> operation. In the sync_to_ucs it's done this way, this patch fixes the
> sync_to_s4 case as well.

Yes, I've changed this: r52019

(In reply to Arvid Requate from comment #16)
> Created attachment 6014 [details]
> UCS_deleted_plain_GUID.patch
> 
> This patch writes the objectGUID as a plain string to the "UCS deleted"
> table, not base64 encoded, improves readability.

Applied with some changes together with a patch for Bug #33621: r52022
Comment 18 Arvid Requate univentionstaff 2014-07-23 17:16:22 CEST
Ok, verified.
Comment 19 Janek Walkenhorst univentionstaff 2014-07-24 15:18:01 CEST
http://errata.univention.de/ucs/3.2/153.html