Univention Bugzilla – Bug 50280
S4 connector sets wrong object class at domaincontroller slave objects
Last modified: 2023-02-17 17:28:50 CET
In UCS@school environments it has become increasingly apparent that the school server objects (domain controller slave) contained the object class "univentionWindows" which is obviously wrong. It is suspected that the "computers/windows" UDM module is used on a DC slave object and as a result, UCS@school UDM hooks also write wrong values to the object (ucsschoolRole: win_computer:school:...). Later on, on a customer system the exact time could be localized via the univention-directory-logger (see below). Apparently the S4 connector synchronized a change from UCS-LDAP to AD-LDAP at 12:00:52 and then tried the back-synchronization AD → UCS around 5 seconds later. At the back-sync the S4 connector was not able to determine the object's UDM type (dc308, is a domaincontroller_slave / school server) and fell back to the default "computers/windows". Modifying the slave object with this wrong UDM module seems to have added the wrong object class. The UCS@school UDM hook uses the UDM module type to set the attribute "ucsschoolRole" accordingly, resulting in the wrong entry "win_computer:school:308". The problem seems to have occurred sometime during the update from 4.3-4 to 4.4-0 and has also been seen post-mortem/without helpful logs in UCS@school development environments set up directly with UCS 4.4. When and how this state can be triggered is still unclear. If you still need log entries, please let us know at short notice. More log files are only available to the customer for a few days. Severity: There is already a fix script in UCS@school, which may be called manually, but the problem may occur again. The new ucsschoolRole attribute is more and more used in UCS@school and the wrong value already caused tracebacks at the customers. 17.07.2019 11:59:06.755 MAIN (------ ): DEBUG_INIT 17.07.2019 11:59:37.493 LDAP (PROCESS): sync from ucs: [ dc] [ modify] cn=dc070,cn=dc,cn=server,cn=computers,ou=070,dc=example,dc=com 17.07.2019 11:59:42.174 LDAP (PROCESS): sync to ucs: [windowscomputer] [ modify] cn=dc070,cn=dc,cn=server,cn=computers,ou=070,dc=example,dc=com 17.07.2019 11:59:42.212 ucsschool.lib.models.school (DEBUG ): Getting all School of None with filter '(objectClass=ucsschoolOrganizationalUnit)' 17.07.2019 12:00:52.480 LDAP (PROCESS): sync from ucs: [ dc] [ modify] cn=dc308,cn=dc,cn=server,cn=computers,ou=308,dc=example,dc=com 17.07.2019 12:00:52.535 LDAP (PROCESS): sync from ucs: [ dc] [ modify] cn=dc076,cn=dc,cn=server,cn=computers,ou=076,dc=example,dc=com 17.07.2019 12:00:57.002 LDAP (ERROR ): get_ucs_object: could not identify UDM object type: cn=dc308,cn=dc,cn=server,cn=computers,ou=308,dc=example,dc=com 17.07.2019 12:00:57.002 LDAP (PROCESS): get_ucs_object: using default: computers/windows 17.07.2019 12:00:57.004 LDAP (PROCESS): sync to ucs: [windowscomputer] [ modify] cn=dc308,cn=dc,cn=server,cn=computers,ou=308,dc=example,dc=com 17.07.2019 12:00:57.049 ucsschool.lib.models.school (DEBUG ): Getting all School of None with filter '(objectClass=ucsschoolOrganizationalUnit)' 17.07.2019 12:00:57.427 LDAP (ERROR ): get_ucs_object: could not identify UDM object type: cn=dc076,cn=dc,cn=server,cn=computers,ou=076,dc=example,dc=com 17.07.2019 12:00:57.427 LDAP (PROCESS): get_ucs_object: using default: computers/windows 17.07.2019 12:00:57.429 LDAP (PROCESS): sync to ucs: [windowscomputer] [ modify] cn=dc076,cn=dc,cn=server,cn=computers,ou=076,dc=example,dc=com 17.07.2019 12:00:57.455 ucsschool.lib.models.school (DEBUG ): Getting all School of None with filter '(objectClass=ucsschoolOrganizationalUnit)' START Old Hash: 55ea38a128e586f793e6f818aa7623dc DN: cn=dc308,cn=dc,cn=server,cn=computers,ou=308,dc=example,dc=com ID: 26847631 Modifier: cn=dc308,cn=dc,cn=server,cn=computers,ou=308,dc=example,dc=com Timestamp: 17.07.2019 10:00:38 Action: modify Old values: univentionOperatingSystemVersion: 4.3-4 modifiersName: cn=admin,dc=example,dc=com entryCSN: 20190716152835.265649Z#000000#000#000000 modifyTimestamp: 20190716152835Z New values: univentionOperatingSystemVersion: 4.4-0 modifiersName: cn=dc308,cn=dc,cn=server,cn=computers,ou=308,dc=example,dc=com entryCSN: 20190717100038.976629Z#000000#000#000000 modifyTimestamp: 20190717100038Z END START Old Hash: 55ea38a128e586f793e6f818aa7623dc DN: cn=dc308,cn=dc,cn=server,cn=computers,ou=308,dc=example,dc=com ID: 26847631 Modifier: cn=dc308,cn=dc,cn=server,cn=computers,ou=308,dc=example,dc=com Timestamp: 17.07.2019 10:00:38 Action: modify Old values: univentionOperatingSystemVersion: 4.3-4 modifiersName: cn=admin,dc=example,dc=com entryCSN: 20190716152835.265649Z#000000#000#000000 modifyTimestamp: 20190716152835Z New values: univentionOperatingSystemVersion: 4.4-0 modifiersName: cn=dc308,cn=dc,cn=server,cn=computers,ou=308,dc=example,dc=com entryCSN: 20190717100038.976629Z#000000#000#000000 modifyTimestamp: 20190717100038Z END START Old Hash: cdd9f291947deedcb480853656697b8e DN: cn=dc064,cn=dc,cn=server,cn=computers,ou=064,dc=example,dc=com ID: 26847633 Modifier: cn=dc064,cn=dc,cn=server,cn=computers,ou=064,dc=example,dc=com Timestamp: 17.07.2019 10:00:57 Action: modify Old values: univentionOperatingSystemVersion: 4.3-4 modifiersName: cn=admin,dc=example,dc=com entryCSN: 20190716152835.477986Z#000000#000#000000 modifyTimestamp: 20190716152835Z New values: univentionOperatingSystemVersion: 4.4-0 modifiersName: cn=dc064,cn=dc,cn=server,cn=computers,ou=064,dc=example,dc=com entryCSN: 20190717100057.003408Z#000000#000#000000 modifyTimestamp: 20190717100057Z END START Old Hash: 0385544e4879f373564f0887e632825c DN: cn=dc699,cn=dc,cn=server,cn=computers,ou=699,dc=example,dc=com ID: 26847634 Modifier: cn=dc699,cn=dc,cn=server,cn=computers,ou=699,dc=example,dc=com Timestamp: 17.07.2019 10:00:57 Action: modify Old values: univentionOperatingSystemVersion: 4.4-0 entryCSN: 20190717095823.488357Z#000000#000#000000 modifyTimestamp: 20190717095823Z New values: univentionOperatingSystemVersion: 4.4-1 entryCSN: 20190717100057.212423Z#000000#000#000000 modifyTimestamp: 20190717100057Z END START Old Hash: 9afff97d902510b601b34442c7d339ca DN: cn=dc308,cn=dc,cn=server,cn=computers,ou=308,dc=example,dc=com ID: 26847635 Modifier: cn=admin,dc=example,dc=com Timestamp: 17.07.2019 10:00:57 Action: modify Old values: modifiersName: cn=dc308,cn=dc,cn=server,cn=computers,ou=308,dc=example,dc=com entryCSN: 20190717100038.976629Z#000000#000#000000 modifyTimestamp: 20190717100038Z New values: objectClass: ucsschoolComputer objectClass: univentionWindows modifiersName: cn=admin,dc=example,dc=com ucsschoolRole: win_computer:school:308 entryCSN: 20190717100057.353232Z#000000#000#000000 modifyTimestamp: 20190717100057Z END START Old Hash: 0005f88228b7b17907ce224fe57bf40e DN: cn=dc076,cn=dc,cn=server,cn=computers,ou=076,dc=example,dc=com ID: 26847636 Modifier: cn=admin,dc=example,dc=com Timestamp: 17.07.2019 10:00:57 Action: modify Old values: modifiersName: cn=dc076,cn=dc,cn=server,cn=computers,ou=076,dc=example,dc=com entryCSN: 20190717100047.768436Z#000000#000#000000 modifyTimestamp: 20190717100047Z New values: objectClass: ucsschoolComputer objectClass: univentionWindows modifiersName: cn=admin,dc=example,dc=com ucsschoolRole: win_computer:school:076 entryCSN: 20190717100057.737383Z#000000#000#000000 modifyTimestamp: 20190717100057Z END
*** Bug 50005 has been marked as a duplicate of this bug. ***
Do you have the connector-s4.log at 20190717100057? And the univention-s4-connector package version running at that time?
(In reply to Florian Best from comment #3) > Do you have the connector-s4.log at 20190717100057? I have a copy of the connector-s4.log but it is only debug level 2 like the excerpt of the connector-s4.log in the bug description. 2019-07-16 09:47:33 status installed univention-s4-connector:all 13.0.2-19A~4.4.0.201906131827
I assume the Univention Directory Logger timestamp is printed with a wrong timezone (-2 hours): The change which breaks the object is printed in the UDL at "17.07.2019 10:00:57" but the connector log messages are from "17.07.2019 12:00:52.480". Can you provide the output of: univention-s4search -b 'cn=dc308,cn=dc,cn=server,cn=computers,ou=308,dc=example,dc=com' '(objectClass=computer)' 'userAccountControl' The breaking change at object "cn=dc308,cn=dc,cn=server,cn=computers,ou=308,dc=example,dc=com" is: objectClass: ucsschoolComputer objectClass: univentionWindows ucsschoolRole: win_computer:school:308 So, this ucsschoolRole thing is added via the hook introduced by Bug #48519. The object class univentionWindows is added because the DN is opened as computers/windows in UDM (This would be prevented by Bug #45096). I assume the S4-Connector mapping is not overwritten by the customer. I assume the sync_to_ucs() was called from univention.s4connector.s4.poll() (otherwise there might be other reasons for the failure). Interesting is that the object is first detected as DC (17.07.2019 12:00:52.480) in sync_from_ucs() and then as windows (17.07.2019 12:00:57.004) in sync_to_ucs(). The con_search_filter from the mapping is used to identify the type of the object when it comes from S4: DC: '(&(objectClass=computer)(userAccountControl:1.2.840.113556.1.4.803:=532480))' Windows: '(&(objectClass=computer)(userAccountControl:1.2.840.113556.1.4.803:=4096))' So, interesting now is: 1. is the _filter_match() function (which evaluates this con_search_filter) broken? (I doubt this) 2. does the userAccountControl attribute contains a value which is compatible to both filters (e.g. 536576) ? 3. did the change in sync_from_ucs() which modifies the S4 object change the userAccountControl to something matching only the Windows filter (4096)?
> I assume the Univention Directory Logger timestamp is printed with a wrong timezone (-2 hours): The timestamps are in UTC: ================ Timestamp: 17.07.2019 10:00:38 Action: modify Old values: [...] New values: modifyTimestamp: 20190717100038Z ================
# univention-s4search -b "cn=dc308,cn=dc,cn=server,cn=computers,ou=308,$(ucr get ldap/base)" '(objectClass=computer)' 'userAccountControl' # record 1 dn: CN=dc308,CN=dc,CN=server,CN=computers,OU=308,DC=schule,dc=example,dc=com userAccountControl: 4096 Looks like only new DC objects have correct userAccountControl (in customer LDAP there are 10 (newer) DC objects with userAccountControl=532480). But there are also more than 100 (older) DC objects with userAccountControl=4096. Did we miss a migration step?
Do we meanwhile have any customer environment where we can reproduce this? I heard rumours that since/when the migration script from Bug #50349 is executed the S4-Connector reverts it? We would like to get ssh access to a environment where this can be reproduced so that we can inspect it interactively.
This is triggered by a rejoin of a UCS@school DC Slave by the joinscript 96univention-samba4slavepdc.inst: The joinscript sets userAccountControl to 4096 under certain conditions. This was introduced in git:4922b2196ec152b8ca9a4f3939501d389bc2ba0a (Bug #41167, Bug #41168). btw, the search filter in the joinscript is also wrong: it searches for userAccountControl=532480 instead of a search filter with a binary matching rule.
The change of userAccountControl happens in /ucs-school-metapackage/96univention-samba4slavepdc.inst in the function _demote_slavepdc_in_central_s4 () This function has been implemented in case a DC Slave has been installed with plain UCS Samba/AD before the UCS@school installation wizard moves it's machine account to the School-OU and re-joins it as Slave PDC. According to the commentary of this function is not needed any more, since Bug #47942 has been resolved.
The script /usr/share/ucs-school-import/scripts/fix_ucsschool_slaves does not correct the wrong userAccountControl, which means the ucsschoolRole will be set to ucsschoolRole: win_computer:school:* at resync by the s4connector. We should adjust this script.
I removed the function _demote_slavepdc_in_central_s4 from the joinscript Successful build Package: ucs-school-metapackage Version: 12.0.2-6A~4.4.0.201912051307 Branch: ucs_4.4-0 Scope: ucs-school-4.4 User: jbremer 6ad20cb3d Bug #50280: yaml 62f015ce6 Bug #50280: Dont set userAccountControl in slave-join-script, not need We still need to find a fix for the already broken objects in school environments installed with ucs < 4.4. without running into the issue from (Bug #41167, Bug #41168).
Successful build Package: ucs-school-import Version: 17.0.19A~4.4.0.201912101148 Branch: ucs_4.4-0 Scope: ucs-school-4.4 User: jbremer d10a9f063 Bug #50280: yaml e54810a5a Bug #50280: fix_ucsschool_slaves now edits the attribute userAccountControl too to avoid recreation of objects with the wrong objectclass at resync The fix_ucsschool_slaves script sets the userAccountcontrol attribute back to DC-Value (532480). Without this change the wrong objectclass win_computer would be set at each resync of the computer object. Since the old join script removed the CN=Configuration container of the slaves which were joined into the masters samba, no drs replication is possible even if userAccountcontrol is set to DC-Value. The QA should check that the issue from Bug #41167 doesn't reappear after running the fix_ucsschool_slaves script.
For QA: Environment: Set up an ucs-school-master Install a dc-slave with samba and join it into the domain. Configure the slave to be an ucs-school-server afterwards. The userAccountControl value should be 4096 now. samba-tool drs showrepl should not show any replication. Update the system resync computer-object -> it should now have the wrong object class win_computer. samba-tool drs kcc samba-tool drs showrepl should not show any replication. Run fix_ucsschool_slaves script: The wrong objectsclass should be removed, userAccountControl should be set correctly again. Resync the computer object The object should still have the correct values. run samba-tool drs kcc (wait a minute) samba-tool drs showrepl should not show any replication to the slave. Look for error messages in /var/log/samba/ which could indicate that replication is attempted but unsuccessful. rejoin slave, check that attributes objectclass, ucsschoolrole and userAccountControl are still set correctly.
Created attachment 10270 [details] patch (git:fbest/50280-enhancements) I have a few considerations about the migration script: 1. There is missing ldap filter escaping. 2. There is the use of subprocess and parsing the output of command line tools. → We should use pure python solutions 3. The bit manipulation uses - and + instead of setting the bits: https://support.microsoft.com/en-us/help/305144/how-to-use-useraccountcontrol-to-manipulate-user-account-properties WORKSTATION_TRUST_ACCOUNT 0x1000 4096 SERVER_TRUST_ACCOUNT 0x2000 8192 TRUSTED_FOR_DELEGATION 0x80000 524288 We have to remove WORKSTATION_TRUST_ACCOUNT and add SERVER_TRUST_ACCOUNT and TRUSTED_FOR_DELEGATION. → Better use int(slave_account_control) & ~4096 | 8192 | 524288 Attached is an example patch which addresses the issues.
Successful build Package: ucs-school-import Version: 17.0.20A~4.4.0.201912131551 Branch: ucs_4.4-0 Scope: ucs-school-4.4 User: jbremer cc148aa90 Bug #50280: update yaml b80f4c7d9 Bug #50280: Enhance fix_ucsschool_slaves script I merged your patch and rebuilt the package. Thank you for the helpful suggestions.
OK: following the instructions from comment 14 I could reproduce the problem OK: problem fixed by removing the userAccountControl change from the joinscript OK: migration script fixes broken objects OK: YAML
UCS@school 4.4 v4 has been released. https://docs.software-univention.de/changelog-ucsschool-4.4v4-de.html If this error occurs again, please clone this bug.