Univention Bugzilla – Bug 51929
Users readded to classes and workgroups they were removed from
Last modified: 2020-11-25 12:07:44 CET
During import students are deactivated and moved to limbo_ou. These students are still members in some classes and groups, referring to their old OU. When they are moved back to an other school this also seems to be the cause of Bug50625!
The customer has to fix the groupmembership of up to 10 users a day, since about two weeks. This is quite annoying for him!
Anonymized traceback: Ein Fehler ist aufgetreten: Die Anfrage konnte nicht bearbeitet werden. Interner Server-Fehler in "schoolusers/query (student)". Interner Server-Fehler in "schoolusers/query (student)". Request: schoolusers/query (student) Traceback (most recent call last): File "/usr/lib/python2.7/dist-packages/univention/management/console/base.py", line 359, in __error_handling six.reraise(etype, exc, etraceback) File "/usr/lib/python2.7/dist-packages/univention/management/console/base.py", line 262, in execute function.__func__(self, request, *args, **kwargs) File "/usr/lib/python2.7/dist-packages/univention/management/console/modules/decorators.py", line 181, in _response return function(self, request) File "/usr/lib/pymodules/python2.7/ucsschool/lib/school_umc_ldap_connection.py", line 141, in wrapper_func return func(*args, **kwargs) File "/usr/lib/pymodules/python2.7/univention/management/console/modules/schoolusers/__init__.py", line 91, in query attr=['givenName', 'sn', 'shadowLastChange', 'shadowMax', 'uid']) File "/usr/lib/pymodules/python2.7/ucsschool/lib/school_umc_base.py", line 318, in _users_ldap " For more information visit https://help.univention.com/t/how-an-ucs-school-user-should-look-like/15630".format(userdn, group)) noObject: User with DN: <user-DN> was not found in the group <group-DN> Please make sure it is a valid UCS@school user and is member of all necessary groups. For more information visit https://help.univention.com/t/how-an-ucs-school-user-should-look-like/15630 How can this traceback be reproduced? Which UMC module or action?
The traceback mentions a missing group member ship. The "memberOf" Attribute of the user shows that the user is in this group. Is this an inconsistency between "memberOf" an "uniquemember"? It is mentioned in the report that a workaround by "fixing group membership" exists, what exactly is done here? One of our scripts or some manual action?
(In reply to Ingo Steuwer from comment #5) > Anonymized traceback: > > Ein Fehler ist aufgetreten: > Die Anfrage konnte nicht bearbeitet werden. > Interner Server-Fehler in "schoolusers/query (student)". > Interner Server-Fehler in "schoolusers/query (student)". > Request: schoolusers/query (student) > > Traceback (most recent call last): > File > "/usr/lib/python2.7/dist-packages/univention/management/console/base.py", > line 359, in __error_handling > six.reraise(etype, exc, etraceback) > File > "/usr/lib/python2.7/dist-packages/univention/management/console/base.py", > line 262, in execute > function.__func__(self, request, *args, **kwargs) > File > "/usr/lib/python2.7/dist-packages/univention/management/console/modules/ > decorators.py", line 181, in _response > return function(self, request) > File > "/usr/lib/pymodules/python2.7/ucsschool/lib/school_umc_ldap_connection.py", > line 141, in wrapper_func > return func(*args, **kwargs) > File > "/usr/lib/pymodules/python2.7/univention/management/console/modules/ > schoolusers/__init__.py", line 91, in query > attr=['givenName', 'sn', 'shadowLastChange', 'shadowMax', 'uid']) > File "/usr/lib/pymodules/python2.7/ucsschool/lib/school_umc_base.py", line > 318, in _users_ldap > " For more information visit > https://help.univention.com/t/how-an-ucs-school-user-should-look-like/15630". > format(userdn, group)) > noObject: User with DN: <user-DN> was not found in the group <group-DN> > Please make sure it is a valid UCS@school user and is member of all > necessary groups. For more information visit > https://help.univention.com/t/how-an-ucs-school-user-should-look-like/15630 > > > How can this traceback be reproduced? Which UMC module or action? This should be described in Bug 50625, where we implemented the link to the documentation.
Based on an internal review: - imports are done using SiSoPi import with Hooks - users are moved from school A to an "intermediate" school and deactivated at the same time - later users are moved from the "intermediate" school to school B an reactivated again - afterwards, all or some of the users have group memberships of school which are not assigned to the user anymore - using @school UMC modules with these users leads to the traceback - workaround is: open the user object in UMC and remove the group memberships for groups which are located in the "old" schools (this is an assumption, needs to be confirmed by the customer) - there is no known other customer with this problem Assumptions are: - moving a user between schools using the SiSoPi import leads to inconsistencies: old group memberships stay while a user is moved to a new school
Because of the new improved logging in the customers import we could verify, that this issue is NOT caused by the sisopi import or any of the implemented hooks. The problem seems to come from the ad-connector or s4-connector or both. So we will change the debugging focus to them.
Ok, yes, at Ticket#2020082621000584 this seems to be caused by the AD-Connector: In my test I imported a testuser1 into a school. Then I stopped the ADC and and then import testuser2 from transfer into the school: /usr/share/ucs-school-import/scripts/ucs-school-user-import -u student -s realschool -c t1.json -i t2.csv --source_uid 'MEINTEST' -l /root/univention-support/import.log The csv only contains testuser2, so the importer moves testuser1 back to the transfer school: root@ucs01:~# univention-ldapsearch -LLL uid=testuser1 memberOf dn: uid=testuser1,cn=schueler,cn=users,ou=transfer,dc=foobar memberOf: cn=schueler-transfer,cn=groups,ou=transfer,dc=foobar memberOf: cn=Domain Users transfer,cn=groups,ou=transfer,dc=foobar The I start the ADC again and wait a couple of seconds and whoosh: root@ucs01:~# univention-ldapsearch -LLL uid=testuser1 memberOf dn: uid=testuser1,cn=schueler,cn=users,ou=transfer,dc=foobar memberOf: cn=schueler-transfer,cn=groups,ou=transfer,dc=foobar memberOf: cn=Domain Users transfer,cn=groups,ou=transfer,dc=foobar memberOf: cn=realschool-11b123,cn=klassen,cn=schueler,cn=groups,ou=realschool,dc=foobar memberOf: cn=schueler-realschool,cn=groups,ou=realschool,dc=foobar From the connector-ad.log it looks a bit like the ADC gets the groups memberships back from AD. No clue yet.
Created attachment 10512 [details] bug51929-issue-pointer.patch The attached patch shows the code location where things go south for the test users. I added a special handling just for them and then the problem seems to be fixed. This reminds me a bit of my S4C bug report Bug 33475, I guess we need to update the group member caches when we sync a UDM user move to AD.
Created attachment 10513 [details] bug51929-issue-pointer.patch Updated patch
(In reply to Arvid Requate from comment #14) > Created attachment 10512 [details] > bug51929-issue-pointer.patch > > The attached patch shows the code location where things go south for the > test users. I added a special handling just for them and then the problem > seems to be fixed. > > This reminds me a bit of my S4C bug report Bug 33475, I guess we need to > update the group member caches when we sync a UDM user move to AD. OK, if it is a problem with group membership after moving objects, maybe this could help Bug #47636. There we added a update mechanism for the group cache after a "move" in the s4 connector. This is currently missing in the ad connector .
multischool master with ad-connector initial setup, all users belong to demoschool dn: uid=louis.sattel,cn=schueler,cn=users,ou=DEMOSCHOOL,dc=four,dc=four ucsschoolSchool: DEMOSCHOOL memberOf: cn=schueler-DEMOSCHOOL,cn=groups,ou=DEMOSCHOOL,dc=four,dc=four memberOf: cn=Domain Users DEMOSCHOOL,cn=groups,ou=DEMOSCHOOL,dc=four,dc=four memberOf: cn=DEMOSCHOOL-1a,cn=klassen,cn=schueler,cn=groups,ou=DEMOSCHOOL,dc=four,dc=four dn: uid=aki.sipker,cn=schueler,cn=users,ou=DEMOSCHOOL,dc=four,dc=four ucsschoolSchool: DEMOSCHOOL memberOf: cn=schueler-DEMOSCHOOL,cn=groups,ou=DEMOSCHOOL,dc=four,dc=four memberOf: cn=Domain Users DEMOSCHOOL,cn=groups,ou=DEMOSCHOOL,dc=four,dc=four memberOf: cn=DEMOSCHOOL-1a,cn=klassen,cn=schueler,cn=groups,ou=DEMOSCHOOL,dc=four,dc=four DN: CN=aki.sipker,CN=schueler,CN=users,OU=DEMOSCHOOL,DC=w2k12,DC=test memberOf: CN=DEMOSCHOOL-1a,CN=klassen,CN=schueler,CN=groups,OU=DEMOSCHOOL,DC=w2k12,DC=test memberOf: CN=schueler-demoschool,CN=groups,OU=DEMOSCHOOL,DC=w2k12,DC=test DN: CN=louis.sattel,CN=schueler,CN=users,OU=DEMOSCHOOL,DC=w2k12,DC=test memberOf: CN=DEMOSCHOOL-1a,CN=klassen,CN=schueler,CN=groups,OU=DEMOSCHOOL,DC=w2k12,DC=test memberOf: CN=schueler-demoschool,CN=groups,OU=DEMOSCHOOL,DC=w2k12,DC=test now i move both users to schule1 (/usr/share/ucs-school-import/scripts/ucs-school-user-import -v -c /usr/share/ucs-school-import/configs/ucs-school-testuser-import.json -i schule1-test_users_2020-10-29_09\:49\:25.csv) first the user louis.sattle is moved 29.10.2020 17:18:13.300 LDAP (PROCESS): sync from ucs: [ user] [ modify] cn=louis.sattel,cn=schueler,cn=users,ou=schule1,DC=w2k12,DC=test dn: uid=louis.sattel,cn=schueler,cn=users,ou=schule1,dc=four,dc=four ucsschoolSchool: schule1 memberOf: cn=Domain Users schule1,cn=groups,ou=schule1,dc=four,dc=four memberOf: cn=schueler-schule1,cn=groups,ou=schule1,dc=four,dc=four memberOf: cn=schule1-1a,cn=klassen,cn=schueler,cn=groups,ou=schule1,dc=four,dc=four dn: uid=aki.sipker,cn=schueler,cn=users,ou=schule1,dc=four,dc=four ucsschoolSchool: schule1 memberOf: cn=Domain Users schule1,cn=groups,ou=schule1,dc=four,dc=four memberOf: cn=schueler-schule1,cn=groups,ou=schule1,dc=four,dc=four memberOf: cn=schule1-1a,cn=klassen,cn=schueler,cn=groups,ou=schule1,dc=four,dc=four DN: CN=aki.sipker,CN=schueler,CN=users,OU=DEMOSCHOOL,DC=w2k12,DC=test memberOf: CN=DEMOSCHOOL-1a,CN=klassen,CN=schueler,CN=groups,OU=DEMOSCHOOL,DC=w2k12,DC=test memberOf: CN=schueler-demoschool,CN=groups,OU=DEMOSCHOOL,DC=w2k12,DC=test DN: CN=louis.sattel,CN=schueler,CN=users,OU=schule1,DC=w2k12,DC=test memberOf: CN=schule1-1a,CN=klassen,CN=schueler,CN=groups,OU=schule1,DC=w2k12,DC=test memberOf: CN=DEMOSCHOOL-1a,CN=klassen,CN=schueler,CN=groups,OU=DEMOSCHOOL,DC=w2k12,DC=test memberOf: CN=schueler-demoschool,CN=groups,OU=DEMOSCHOOL,DC=w2k12,DC=test memberOf: CN=schueler-schule1,CN=groups,OU=schule1,DC=w2k12,DC=test membership is correctly updated (now in schule1 groups) now 29.10.2020 17:21:44.787 LDAP (PROCESS): sync from ucs: [ group] [ modify] cn=schueler-demoschool,cn=groups,ou=demoschool,DC=w2k12,DC=test and here i see 29.10.2020 17:23:28.248 LDAP (INFO ): group_members_sync_from_ucs: ad_members_from_ucs without members with this as their primary group: [u'cn=demo_student,cn=schueler,cn=users,ou=demoschool,dc=w2k12,dc=test'] 29.10.2020 17:23:28.249 LDAP (INFO ): group_members_sync_from_ucs: members to add initialized: [u'cn=demo_student,cn=schueler,cn=users,ou=demoschool,dc=w2k12,dc=test'] 29.10.2020 17:23:28.249 LDAP (INFO ): group_members_sync_from_ucs: members to del initialized: [] 29.10.2020 17:23:28.249 LDAP (INFO ): group_members_sync_from_ucs: CN=aki.sipker,CN=schueler,CN=users,OU=DEMOSCHOOL,DC=w2k12,DC=test in ad_members_from_ucs? 29.10.2020 17:23:28.249 LDAP (INFO ): group_members_sync_from_ucs: No 29.10.2020 17:23:28.250 LDAP (INFO ): group_members_sync_from_ucs: CN=louis.sattel,CN=schueler,CN=users,OU=schule1,DC=w2k12,DC=test in ad_members_from_ucs? 29.10.2020 17:23:28.250 LDAP (INFO ): group_members_sync_from_ucs: cn=louis.sattel,cn=schueler,cn=users,ou=schule1,dc=w2k12,dc=test was not found in group member con cache of cn=schueler-demoschool,cn=groups,ou=demoschool,dc=w2k12,dc=test, don't delete 29.10.2020 17:23:28.250 LDAP (INFO ): group_members_sync_from_ucs: CN=demo_student,CN=schueler,CN=users,OU=DEMOSCHOOL,DC=w2k12,DC=test in ad_members_from_ucs? 29.10.2020 17:23:28.251 LDAP (INFO ): group_members_sync_from_ucs: Yes 29.10.2020 17:23:28.251 LDAP (INFO ): group_members_sync_from_ucs: members to add: [] 29.10.2020 17:23:28.251 LDAP (INFO ): group_members_sync_from_ucs: members to del: [u'CN=aki.sipker,CN=schueler,CN=users,OU=DEMOSCHOOL,DC=w2k12,DC=test'] so louis.sattel is not removed from schueler-demoschool (as he should) because the new DN seem to be missing in the group cache, only the not yet moved user is removed from this groups in ad dn: uid=louis.sattel,cn=schueler,cn=users,ou=schule1,dc=four,dc=four ucsschoolSchool: schule1 memberOf: cn=Domain Users schule1,cn=groups,ou=schule1,dc=four,dc=four memberOf: cn=schueler-schule1,cn=groups,ou=schule1,dc=four,dc=four memberOf: cn=schule1-1a,cn=klassen,cn=schueler,cn=groups,ou=schule1,dc=four,dc=four dn: uid=aki.sipker,cn=schueler,cn=users,ou=schule1,dc=four,dc=four ucsschoolSchool: schule1 memberOf: cn=Domain Users schule1,cn=groups,ou=schule1,dc=four,dc=four memberOf: cn=schueler-schule1,cn=groups,ou=schule1,dc=four,dc=four memberOf: cn=schule1-1a,cn=klassen,cn=schueler,cn=groups,ou=schule1,dc=four,dc=four DN: CN=aki.sipker,CN=schueler,CN=users,OU=DEMOSCHOOL,DC=w2k12,DC=test memberOf: CN=DEMOSCHOOL-1a,CN=klassen,CN=schueler,CN=groups,OU=DEMOSCHOOL,DC=w2k12,DC=test DN: CN=louis.sattel,CN=schueler,CN=users,OU=schule1,DC=w2k12,DC=test memberOf: CN=schule1-1a,CN=klassen,CN=schueler,CN=groups,OU=schule1,DC=w2k12,DC=test memberOf: CN=DEMOSCHOOL-1a,CN=klassen,CN=schueler,CN=groups,OU=DEMOSCHOOL,DC=w2k12,DC=test memberOf: CN=schueler-demoschool,CN=groups,OU=DEMOSCHOOL,DC=w2k12,DC=test memberOf: CN=schueler-schule1,CN=groups,OU=schule1,DC=w2k12,DC=test the same goes for the demoschool-1a group, so that we end up with this dn: uid=louis.sattel,cn=schueler,cn=users,ou=schule1,dc=four,dc=four ucsschoolSchool: schule1 memberOf: cn=Domain Users schule1,cn=groups,ou=schule1,dc=four,dc=four memberOf: cn=schueler-schule1,cn=groups,ou=schule1,dc=four,dc=four memberOf: cn=schule1-1a,cn=klassen,cn=schueler,cn=groups,ou=schule1,dc=four,dc=four dn: uid=aki.sipker,cn=schueler,cn=users,ou=schule1,dc=four,dc=four ucsschoolSchool: schule1 memberOf: cn=Domain Users schule1,cn=groups,ou=schule1,dc=four,dc=four memberOf: cn=schueler-schule1,cn=groups,ou=schule1,dc=four,dc=four memberOf: cn=schule1-1a,cn=klassen,cn=schueler,cn=groups,ou=schule1,dc=four,dc=four DN: CN=aki.sipker,CN=schueler,CN=users,OU=DEMOSCHOOL,DC=w2k12,DC=test DN: CN=louis.sattel,CN=schueler,CN=users,OU=schule1,DC=w2k12,DC=test memberOf: CN=schule1-1a,CN=klassen,CN=schueler,CN=groups,OU=schule1,DC=w2k12,DC=test memberOf: CN=DEMOSCHOOL-1a,CN=klassen,CN=schueler,CN=groups,OU=DEMOSCHOOL,DC=w2k12,DC=test memberOf: CN=schueler-demoschool,CN=groups,OU=DEMOSCHOOL,DC=w2k12,DC=test memberOf: CN=schueler-schule1,CN=groups,OU=schule1,DC=w2k12,DC=test at some point the sync for these groups come back to UCS (triggerd by the removal of aki) and louis is readded in UCS to 29.10.2020 17:34:46.341 LDAP (PROCESS): sync to ucs: [ group] [ modify] cn=schueler-demoschool,cn=groups,ou=demoschool,dc=four,dc=four ... 29.10.2020 17:35:24.960 LDAP (PROCESS): sync to ucs: [ group] [ modify] cn=demoschool-1a,cn=klassen,cn=schueler,cn=groups,ou=demoschool,dc=four,dc=four dn: uid=louis.sattel,cn=schueler,cn=users,ou=schule1,dc=four,dc=four ucsschoolSchool: schule1 memberOf: cn=Domain Users schule1,cn=groups,ou=schule1,dc=four,dc=four memberOf: cn=schueler-schule1,cn=groups,ou=schule1,dc=four,dc=four memberOf: cn=schule1-1a,cn=klassen,cn=schueler,cn=groups,ou=schule1,dc=four,dc=four memberOf: cn=demoschool-1a,cn=klassen,cn=schueler,cn=groups,ou=demoschool,dc=four,dc=four memberOf: cn=schueler-demoschool,cn=groups,ou=demoschool,dc=four,dc=four dn: uid=aki.sipker,cn=schueler,cn=users,ou=schule1,dc=four,dc=four ucsschoolSchool: schule1 memberOf: cn=Domain Users schule1,cn=groups,ou=schule1,dc=four,dc=four memberOf: cn=schueler-schule1,cn=groups,ou=schule1,dc=four,dc=four memberOf: cn=schule1-1a,cn=klassen,cn=schueler,cn=groups,ou=schule1,dc=four,dc=four DN: CN=aki.sipker,CN=schueler,CN=users,OU=schule1,DC=w2k12,DC=test memberOf: CN=schule1-1a,CN=klassen,CN=schueler,CN=groups,OU=schule1,DC=w2k12,DC=test memberOf: CN=schueler-schule1,CN=groups,OU=schule1,DC=w2k12,DC=test DN: CN=louis.sattel,CN=schueler,CN=users,OU=schule1,DC=w2k12,DC=test memberOf: CN=schule1-1a,CN=klassen,CN=schueler,CN=groups,OU=schule1,DC=w2k12,DC=test memberOf: CN=DEMOSCHOOL-1a,CN=klassen,CN=schueler,CN=groups,OU=DEMOSCHOOL,DC=w2k12,DC=test memberOf: CN=schueler-demoschool,CN=groups,OU=DEMOSCHOOL,DC=w2k12,DC=test memberOf: CN=schueler-schule1,CN=groups,OU=schule1,DC=w2k12,DC=test so i think it is similar to Bug #47636, we have to update the group cache after moving users (or use id's instead of dn's?)
> or use id's instead of dn's? You mean objectGUIDs? That may be a great idea! Unless a) if it's more expensive to the the objectGUIDs of the group members b) if we need the DNs to perform some ignore-subtree filtering of the group members Maybe for a) we could make use of the extended-dn control during searches, see, e.g. the output of: univention-s4search member=* member --extended-dn OTOH, I vaguely remember samba-tool dbcheck messages of cases where some part of the extended-DNS where not really up to date. So we should check with an updated system which has seen some activity (UCS@school?) to see if this is a safe foundation. And then there's the migration effort from the DN-based solution to the new one, but that may be worth it. Either slowly on the fly or by doing the migration during update (this could happen in a postinst by reading directly from sam.ldb).
If we do objectGUIDs then please store them in a readable format in the sqlite table. We have one or two where we made the ugly design decision to write base64-encoded binary structures. That's always a PITA during support cases - excuse my french.
4ac7ea99b31634c669cddb3b51182b793fb5ad63 - univention-ad-connector So it was not the same as Bug #47636, nevertheless i have merge those patches into the ad-connector as well. These are necessary changes for updating the group_mapping_cache_con/ucs and to clarify the handling and log message of the move operation. Additionally i added _update_group_member_cache for move and remove. For move all the old_dns in the group-member_cache are replaced with the new one's. For remove the dn's are just removed. 4ac7ea99b31634c669cddb3b51182b793fb5ad63 - yaml c2eeb20f47f70f74aa4c5569ee3fadd00adfc39a - ucs-test This problem can easily be reproduced without the school setup. I have added the test 55_adconnector/504_test_group_cache_after_move. I think the important fact here is to stop the connector before moving the object and changing the group membership (this is what ucs-school-user-import does). After these operation restart the connector. I have also added a simple reproducer for an school environment (reproduce.sh). QA please also manually or with the reproducer check the fix in a school environment. TODO: check jenkins tests TODO: merge request
Created attachment 10543 [details] reproducer.sh
An other customer seems to have this problem. He reported that imported users are fine, but students who will leave school, are deactivated as expected, but these students are still members of the classes and workgroups. The customer has the ad connector installed on the master. univention-app info UCS: 4.4-6 errata796 Installed: adconnector=12.0 itslearning=3.2 pkgdb=11.0 samba4=4.10 self-service-backend=4.0 ucsschool=4.4 v7 Connector is in syncmode. connector/ad/mapping/syncmode: sync
Jenkins tests look good. Added merge request. univention-ad-connector - 1ea1f3f586482cd06d66d9b6cf8a53e3159c9816 added _update_group_member_cache ucs-test - c2eeb20f47f70f74aa4c5569ee3fadd00adfc39a added 55_adconnector/504test_group_cache_after_move
Problem is not reproducible any more on: School with AD: OK School with AD+S4: OK UCS with AD+S4: FAIL -> new bug UCS with AD: OK YAML: OK UCS_TEST: OK So the Ad-connector portion works as expected, the problem is not reproducible. The test fails in the UCS with AD+S4 setup. The s4connector logs 11.11.2020 15:26:41.499 LDAP (PROCESS): group_members_sync_from_ucs: cn=hbtwedcq,dc=autotest237,dc=local was not found in S4 group member cache of cn=ybqkedcr,cn=groups,dc=autotest237,dc=local, don't delete Interestingly though, in my UCS@School setup with ADConnector and S4Connector, everything worked fine. It only fails with "normal" UCS with S4+AD. I don't know why yet. Seems to be a similar problem like we just fixed in the ad connector. I will open another bug for this. The AD part is VERIFIED
<https://errata.software-univention.de/#/?erratum=4.4x821>