Bug 43247 - Regression: sync_to_ucs of new joined windows client fails with traceback
Regression: sync_to_ucs of new joined windows client fails with traceback
Status: CLOSED FIXED
Product: UCS
Classification: Unclassified
Component: UDM (Generic)
UCS 4.1
Other Linux
: P1 critical (vote)
: UCS 4.1-4-errata
Assigned To: Florian Best
Stefan Gohmann
:
: 28756 32638 37632 43281 (view as bug list)
Depends on:
Blocks: 43286
  Show dependency treegraph
 
Reported: 2016-12-23 02:59 CET by Arvid Requate
Modified: 2017-03-17 10:55 CET (History)
6 users (show)

See Also:
What kind of report is it?: Bug Report
What type of bug is this?: 5: Major Usability: Impairs usability in key scenarios
Who will be affected by this bug?: 4: Will affect most installed domains
How will those affected feel about the bug?: 3: A User would likely not purchase the product
User Pain: 0.343
Enterprise Customer affected?: Yes
School Customer affected?:
ISV affected?:
Waiting Support:
Flags outvoted (downgraded) after PO Review:
Ticket number: 2016121621000611, 2017010221000531, 2017010321002152, 2016121921000285, 2017010421000483, 2017031621000733
Bug group (optional):
Max CVSS v3 score:


Attachments
connector-s4.log (227.46 KB, text/x-log)
2016-12-23 02:59 CET, Arvid Requate
Details
hotfix (2.03 KB, patch)
2016-12-23 09:38 CET, Florian Best
Details | Diff

Note You need to log in before you can comment on or make changes to this bug.
Description Arvid Requate univentionstaff 2016-12-23 02:59:01 CET
Created attachment 8322 [details]
connector-s4.log

23.11.2015 20:39:23,620 LDAP        (PROCESS): sync to ucs:   [windowscomputer] [       add] cn=
After joining a Windows Client into Samba/AD (v4.5.3) the synchronization of the machine account to OpenLDAP fails with a traceback:

=========================================================================
23.11.2015 20:39:23,620 LDAP        (PROCESS): sync to ucs:   [windowscomputer] [       add] cn=WIN7PRO230,CN=Computers,dc=ar41i1,dc=qa
23.11.2015 20:39:24,129 LDAP        (ERROR  ): Unknown Exception during sync_to_ucs
23.11.2015 20:39:24,130 LDAP        (ERROR  ): Traceback (most recent call last):
  File "/usr/lib/pymodules/python2.7/univention/s4connector/__init__.py", line 1475, in sync_to_ucs
    result = self.add_in_ucs(property_type, object, module, position)
  File "/usr/lib/pymodules/python2.7/univention/s4connector/__init__.py", line 1262, in add_in_ucs
    return ucs_object.create() and self.__modify_custom_attributes(property_type, object, ucs_object, module, position)
  File "/usr/lib/pymodules/python2.7/univention/admin/handlers/__init__.py", line 305, in create
    return self._create()
  File "/usr/lib/pymodules/python2.7/univention/admin/handlers/__init__.py", line 764, in _create
    self._ldap_post_create()
  File "/usr/lib/pymodules/python2.7/univention/admin/handlers/computers/windows.py", line 479, in _ldap_post_create
    univention.admin.handlers.simpleComputer._ldap_post_create(self)
  File "/usr/lib/pymodules/python2.7/univention/admin/handlers/__init__.py", line 2359, in _ldap_post_create
    self.update_groups()
  File "/usr/lib/pymodules/python2.7/univention/admin/handlers/__init__.py", line 2454, in update_groups
    groupObject.modify(ignore_license=1)
  File "/usr/lib/pymodules/python2.7/univention/admin/handlers/__init__.py", line 316, in modify
    return self._modify(modify_childs, ignore_license=ignore_license)
  File "/usr/lib/pymodules/python2.7/univention/admin/handlers/__init__.py", line 810, in _modify
    self.lo.modify(self.dn, ml, ignore_license=ignore_license)
  File "/usr/lib/pymodules/python2.7/univention/admin/uldap.py", line 403, in modify
    raise univention.admin.uexceptions.ldapError(_err2str(msg), original_exception=msg)
ldapError: Type or value exists: modify/add: uniqueMember: value #0 already exists

23.11.2015 20:39:24,131 LDAP        (WARNING): sync to ucs was not successfull, save rejected
23.11.2015 20:39:24,131 LDAP        (WARNING): object was: CN=WIN7PRO230,CN=Computers,DC=ar41i1,DC=qa
23.11.2015 20:39:29,175 LDAP        (PROCESS): sync from ucs: [windowscomputer] [       add] CN=WIN7PRO230,CN=Computers,DC=ar41i1,DC=qa
23.11.2015 20:39:29,176 LDAP        (PROCESS): Unable to sync CN=WIN7PRO230,CN=Computers,DC=ar41i1,DC=qa (GUID: 731a96da-4def-4904-8f87-5e22e48ebcd5). The object is currently locked.
23.11.2015 20:39:29,182 LDAP        (PROCESS): sync from ucs: [windowscomputer] [    delete] CN=WIN7PRO230,CN=Computers,DC=ar41i1,DC=qa
23.11.2015 20:39:29,183 LDAP        (PROCESS): Unable to sync CN=WIN7PRO230,CN=Computers,DC=ar41i1,DC=qa (GUID: 731a96da-4def-4904-8f87-5e22e48ebcd5). The object is currently locked.
=========================================================================

* happens with univention-s4-connector 10.0.4-4.629.201612131743
* doesn't happen with 10.0.3-4.625.201611231337

Level 4 logs attached.
Comment 1 Arvid Requate univentionstaff 2016-12-23 03:03:16 CET
I also checked with UCS 4.1-4 errata 353 (still Samba 4.5-1) and just updated univention-s4-connector via:

univention-install univention-s4-connector=10.0.4-4.629.201612131743

Same issue.
Comment 2 Stefan Gohmann univentionstaff 2016-12-23 07:42:04 CET
It took me a while to detect that it only happen if the windows host name is upper case.

Anyway, it looks for me that the latest S4 connector version doesn't convert the position to lowercase. I guess due to Bug #42393:

The following commands show the problem:

root@master411:~# udm computers/windows create --set name=win1 --position "cn=computers,$(ucr get ldap/base)"
Object created: cn=win1,cn=computers,dc=deadlock41,dc=intranet
root@master411:~# udm computers/windows create --set name=win2 --position "cn=Computers,$(ucr get ldap/base)"
Object created: cn=win2,cn=Computers,dc=deadlock41,dc=intranet
root@master411:~# udm computers/windows create --set name=win3 --position "CN=computers,$(ucr get ldap/base)"
LDAP Error: Type or value exists: modify/add: uniqueMember: value #0 already exists
root@master411:~# 

@Florian, I suggest to fix it in UDM. What do you think?
Comment 3 Florian Best univentionstaff 2016-12-23 09:38:35 CET
Created attachment 8323 [details]
hotfix

  File "/usr/share/pyshared/univention/admincli/admin.py", line 35, in <module>
    import getopt
  File "/usr/share/pyshared/univention/admincli/admin.py", line 404, in doit
    out = _doit(arglist)
  File "/usr/share/pyshared/univention/admincli/admin.py", line 747, in _doit
    dn = object.create()
  File "/usr/lib/pymodules/python2.7/univention/admin/handlers/__init__.py", line 305, in create
    return self._create()
  File "/usr/lib/pymodules/python2.7/univention/admin/handlers/__init__.py", line 764, in _create
    self._ldap_post_create()
  File "/usr/lib/pymodules/python2.7/univention/admin/handlers/computers/windows.py", line 474, in _ldap_post_create
    univention.admin.handlers.simpleComputer._ldap_post_create(self)
  File "/usr/lib/pymodules/python2.7/univention/admin/handlers/__init__.py", line 2365, in _ldap_post_create
    self.update_groups()
  File "/usr/lib/pymodules/python2.7/univention/admin/handlers/__init__.py", line 2460, in update_groups
    groupObject.modify(ignore_license=1)
  File "/usr/lib/pymodules/python2.7/univention/admin/handlers/__init__.py", line 316, in modify
    return self._modify(modify_childs, ignore_license=ignore_license)
  File "/usr/lib/pymodules/python2.7/univention/admin/handlers/__init__.py", line 810, in _modify
    self.lo.modify(self.dn, ml, ignore_license=ignore_license)
  File "/usr/lib/pymodules/python2.7/univention/admin/uldap.py", line 403, in modify
    raise univention.admin.uexceptions.ldapError(_err2str(msg), original_exception=msg)
ldapError: Type or value exists: modify/add: uniqueMember: value #0 already exists
Comment 4 Stefan Gohmann univentionstaff 2016-12-23 10:05:37 CET
Thanks, the hotfix helps in my tests.

I've added two test cases to demonstrate this issue (r75533):
 52_s4connector/406create_windows_computer
 52_s4connector/406create_windows_computer_upper_case
Comment 5 Florian Best univentionstaff 2016-12-23 12:29:57 CET
The patch can be applied by executing the following commands:
wget --no-check-certificate 'https://forge.univention.org/bugzilla/attachment.cgi?id=8323' -O hotfix_43247.patch
patch -p7 -d /usr/share/pyshared/univention/admin/handlers/ <hotfix_43247.patch
/etc/init.d/univention-s4-connector restart
Comment 6 Arvid Requate univentionstaff 2016-12-23 13:03:57 CET
Ok, patch works for me, but we have to crestart (*c*) univention-s4-connector in postinst to make this take effect.
Comment 7 Florian Best univentionstaff 2016-12-23 14:31:40 CET
*** Bug 32638 has been marked as a duplicate of this bug. ***
Comment 8 Florian Best univentionstaff 2016-12-23 14:32:17 CET
*** Bug 28756 has been marked as a duplicate of this bug. ***
Comment 9 Florian Best univentionstaff 2016-12-23 14:42:09 CET
I fixed this at the more central station directly in groups/group so that other places with wrong usage will also be correct.

univention-directory-manager-modules (11.0.3.52):
r75538 | Bug #43247: compare LDAP DN's correctly when adding/removing group members

univention-directory-manager-modules.yaml:
r75539 | YAML Bug #43247
Comment 10 Stefan Gohmann univentionstaff 2017-01-03 07:15:38 CET
Please have a look here:

http://jenkins.knut.univention.de:8080/job/UCSschool%204.1/job/UCSschool%204.1%20(R2)%20Multiserver/347/SambaVersion=s4-only-master/testReport/10_ldap/62check_ldap_group_to_file/test/

(2017-01-02 18:41:59.859251) info 2017-01-02 18:41:59	 remove user ywötykfn from group bhjtcwvb
[2017-01-02 18:42:00.001688] Traceback (most recent call last):
[2017-01-02 18:42:00.001723]   File "/usr/share/univention-directory-manager-tools/univention-cli-server", line 222, in doit
[2017-01-02 18:42:00.001737]     output = univention.admincli.admin.doit(arglist)
[2017-01-02 18:42:00.001748]   File "/usr/lib/pymodules/python2.7/univention/admincli/admin.py", line 404, in doit
[2017-01-02 18:42:00.001758]     out = _doit(arglist)
[2017-01-02 18:42:00.001767]   File "/usr/lib/pymodules/python2.7/univention/admincli/admin.py", line 898, in _doit
[2017-01-02 18:42:00.001775]     dn = object.modify()
[2017-01-02 18:42:00.001786]   File "/usr/lib/pymodules/python2.7/univention/admin/handlers/__init__.py", line 317, in modify
[2017-01-02 18:42:00.001796]     return self._modify(modify_childs, ignore_license=ignore_license)
[2017-01-02 18:42:00.001806]   File "/usr/lib/pymodules/python2.7/univention/admin/handlers/__init__.py", line 805, in _modify
[2017-01-02 18:42:00.001815]     ml = self._ldap_modlist()
[2017-01-02 18:42:00.001827]   File "/usr/lib/pymodules/python2.7/univention/admin/handlers/groups/group.py", line 642, in _ldap_modlist
[2017-01-02 18:42:00.001838]     uniqueMemberRemove = keepCase(uniqueMemberRemove, old)
[2017-01-02 18:42:00.001849]   File "/usr/lib/pymodules/python2.7/univention/admin/handlers/groups/group.py", line 634, in keepCase
[2017-01-02 18:42:00.001883]     mapping = dict((x.lower(), x) for x in oldMembers)
[2017-01-02 18:42:00.001895]   File "/usr/lib/pymodules/python2.7/univention/admin/handlers/groups/group.py", line 634, in <genexpr>
[2017-01-02 18:42:00.001904]     mapping = dict((x.lower(), x) for x in oldMembers)
[2017-01-02 18:42:00.001912] AttributeError: 'DN' object has no attribute 'lower'
(2017-01-02 18:42:00.015217) error 2017-01-02 18:42:00	 **************** Test failed above this line (1) ****************
Comment 11 Florian Best univentionstaff 2017-01-03 11:47:11 CET
univention-directory-manager-modules (11.0.3-53):
r75559 | Bug #43247: fixup
univention-directory-manager-modules (12.0.11-1):
r75560 | Bug #43247: fixup
Comment 12 Nico Stöckigt univentionstaff 2017-01-03 12:40:34 CET
UCS 4.1-4 e366 (single master)

with applied Hotfix the Traceback also occured and ends in an object lock.

-----8<-----
03.01.2017 11:58:17,288 LDAP        (PROCESS): sync to ucs:   [windowscomputer] [       add] cn=WIN7-DESKTOP,CN=Computers,dc=univention,dc=test
03.01.2017 11:58:18,879 LDAP        (ERROR  ): Unknown Exception during sync_to_ucs
03.01.2017 11:58:18,879 LDAP        (ERROR  ): Traceback (most recent call last):
  File "/usr/lib/pymodules/python2.7/univention/s4connector/__init__.py", line 1475, in sync_to_ucs
    result = self.add_in_ucs(property_type, object, module, position)
  File "/usr/lib/pymodules/python2.7/univention/s4connector/__init__.py", line 1262, in add_in_ucs
    return ucs_object.create() and self.__modify_custom_attributes(property_type, object, ucs_object, module, position)
  File "/usr/lib/pymodules/python2.7/univention/admin/handlers/__init__.py", line 305, in create
    return self._create()
  File "/usr/lib/pymodules/python2.7/univention/admin/handlers/__init__.py", line 764, in _create
    self._ldap_post_create()
  File "/usr/lib/pymodules/python2.7/univention/admin/handlers/computers/windows.py", line 478, in _ldap_post_create
    univention.admin.handlers.simpleComputer.update_groups(self)
  File "/usr/lib/pymodules/python2.7/univention/admin/handlers/__init__.py", line 2456, in update_groups
    groupObject.modify(ignore_license=1)
  File "/usr/lib/pymodules/python2.7/univention/admin/handlers/__init__.py", line 316, in modify
    return self._modify(modify_childs, ignore_license=ignore_license)
  File "/usr/lib/pymodules/python2.7/univention/admin/handlers/__init__.py", line 810, in _modify
    self.lo.modify(self.dn, ml, ignore_license=ignore_license)
  File "/usr/lib/pymodules/python2.7/univention/admin/uldap.py", line 403, in modify
    raise univention.admin.uexceptions.ldapError(_err2str(msg), original_exception=msg)
ldapError: Type or value exists: modify/add: memberUid: value #0 already exists

03.01.2017 11:58:18,879 LDAP        (WARNING): sync to ucs was not successfull, save rejected
03.01.2017 11:58:18,879 LDAP        (WARNING): object was: cn=WIN7-DESKTOP,CN=Computers,dc=univention,dc=test
03.01.2017 11:58:24,122 LDAP        (PROCESS): sync from ucs: [windowscomputer] [       add] cn=WIN7-DESKTOP,CN=Computers,dc=univention,dc=test
03.01.2017 11:58:24,123 LDAP        (PROCESS): Unable to sync cn=WIN7-DESKTOP,CN=Computers,dc=univention,dc=test (GUID: a8811acb-58d3-4397-9619-f6628ac62554). The object is currently locked
----->8-----

Removing the lock entries from db removes the computer from S4-AD.
Comment 13 Stefan Gohmann univentionstaff 2017-01-03 21:05:28 CET
(In reply to Arvid Requate from comment #6)
> Ok, patch works for me, but we have to crestart (*c*)
> univention-s4-connector in postinst to make this take effect.

@Florian, I think a restart would be helpful.
Comment 14 Stefan Gohmann univentionstaff 2017-01-04 09:59:51 CET
(In reply to Stefan Gohmann from comment #13)
> (In reply to Arvid Requate from comment #6)
> > Ok, patch works for me, but we have to crestart (*c*)
> > univention-s4-connector in postinst to make this take effect.
> 
> @Florian, I think a restart would be helpful.

Never mind, we will also provide a S4 Connector erratum which will restart the S4 Connector.
Comment 15 Florian Best univentionstaff 2017-01-04 12:12:55 CET
*** Bug 43281 has been marked as a duplicate of this bug. ***
Comment 16 Florian Best univentionstaff 2017-01-04 13:02:41 CET
*** Bug 37632 has been marked as a duplicate of this bug. ***
Comment 17 Florian Best univentionstaff 2017-01-04 14:30:36 CET
Added a test case which checks hosts, nested groups and users with uid=..., UID=... and uID=....

ucs-test (7.0.6-38):
r75577 | Bug #43247: add test case 62_udm-groups/24_group_different_case
ucs-test (6.0.37-31):
r75576 | Bug #43247: add test case 62_udm-groups/24_group_different_case

I created Bug #43286 for the UDM-CLI script which cannot handle different case for --remove currently.
The DN's uid=foo and uid=Foo are from LDAP perspective also equal but this is still neglected as it would require to parse the schema. The newly introduced class "univention.admin.uldap.DN" should somewhen be adapted to do this.
Comment 18 Stefan Gohmann univentionstaff 2017-01-04 15:58:11 CET
Tests: OK

UCS Test: OK

Code review: OK

YAML: OK

UCS 4.2 merge: OK
Comment 19 Florian Best univentionstaff 2017-01-04 17:40:52 CET
(In reply to Nico Stöckigt from comment #12)
> UCS 4.1-4 e366 (single master)
> 
> with applied Hotfix the Traceback also occured and ends in an object lock.> ldapError: Type or value exists: modify/add: memberUid: value #0 already
> exists
…

The reason why this fail here is the attribute "memberUid" not "uniqueMember" which is already set at that object because the listener failed for that object the first time.
I fixed this in the package but not in that hotfix-patch. If you manually remove the already set memberUid you can continue using the hotfix. Or you just wait for the release tomorrow.
Comment 20 Janek Walkenhorst univentionstaff 2017-01-05 11:22:44 CET
<http://errata.software-univention.de/ucs/4.1/367.html>