Univention Bugzilla – Bug 48626
ignore cn=temporary,cn=univention DN's in translog overlay
Last modified: 2022-02-11 13:04:26 CET
With bug #48427 we are starting to store the transactions in a LDAP database. To reduce the number of write operations and the amount of disk space needed for the LDAP translog database, we should think about ignoring the temporary objects (cn=temporary,cn=univention) in the translog overlay.
CRITICAL: no change of listener transaction id for last 0 checks (nid=6795111 lid=2053989) The transaction which causes the database to fill up are mostly these entries: 14.04.21 15:57:39.479 LISTENER ( PROCESS ) : updating 'cn=S-1-5-21-2124116158-320203473-397726588-1205,cn=sid,cn=temporary,cn=univention,dc=sas,dc=schein,dc=ig' command d 14.04.21 15:57:39.493 LISTENER ( PROCESS ) : updating 'cn=S-1-5-21-2124116158-320203473-397726588-1206,cn=sid,cn=temporary,cn=univention,dc=sas,dc=schein,dc=ig' command a 14.04.21 15:57:39.512 LISTENER ( PROCESS ) : updating 'cn=S-1-5-21-2124116158-320203473-397726588-1206,cn=sid,cn=temporary,cn=univention,dc=sas,dc=schein,dc=ig' command d 14.04.21 15:57:39.535 LISTENER ( PROCESS ) : updating 'cn=S-1-5-21-2124116158-320203473-397726588-1207,cn=sid,cn=temporary,cn=univention,dc=sas,dc=schein,dc=ig' command a 14.04.21 15:57:39.557 LISTENER ( PROCESS ) : updating 'cn=S-1-5-21-2124116158-320203473-397726588-1207,cn=sid,cn=temporary,cn=univention,dc=sas,dc=schein,dc=ig' command d 14.04.21 15:57:39.589 LISTENER ( PROCESS ) : updating 'cn=S-1-5-21-2124116158-320203473-397726588-1208,cn=sid,cn=temporary,cn=univention,dc=sas,dc=schein,dc=ig' command a 14.04.21 15:57:39.610 LISTENER ( PROCESS ) : updating 'cn=S-1-5-21-2124116158-320203473-397726588-1208,cn=sid,cn=temporary,cn=univention,dc=sas,dc=schein,dc=ig' command d 14.04.21 15:57:39.640 LISTENER ( PROCESS ) : updating 'cn=S-1-5-21-2124116158-320203473-397726588-1209,cn=sid,cn=temporary,cn=univention,dc=sas,dc=schein,dc=ig' command a 14.04.21 15:57:39.663 LISTENER ( PROCESS ) : updating 'cn=S-1-5-21-2124116158-320203473-397726588-1209,cn=sid,cn=temporary,cn=univention,dc=sas,dc=schein,dc=ig' command d 14.04.21 15:57:39.681 LISTENER ( PROCESS ) : updating 'cn=S-1-5-21-2124116158-320203473-397726588-1210,cn=sid,cn=temporary,cn=univention,dc=sas,dc=schein,dc=ig' command a 14.04.21 15:57:39.697 LISTENER ( PROCESS ) : updating 'cn=S-1-5-21-2124116158-320203473-397726588-1210,cn=sid,cn=temporary,cn=univention,dc=sas,dc=schein,dc=ig' command d 14.04.21 15:57:39.728 LISTENER ( PROCESS ) : updating 'cn=S-1-5-21-2124116158-320203473-397726588-1211,cn=sid,cn=temporary,cn=univention,dc=sas,dc=schein,dc=ig' command a 14.04.21 15:57:39.746 LISTENER ( PROCESS ) : updating 'cn=S-1-5-21-2124116158-320203473-397726588-1211,cn=sid,cn=temporary,cn=univention,dc=sas,dc=schein,dc=ig' command d 14.04.21 15:57:39.765 LISTENER ( PROCESS ) : updating 'cn=S-1-5-21-2124116158-320203473-397726588-1213,cn=sid,cn=temporary,cn=univention,dc=sas,dc=schein,dc=ig' command a 14.04.21 15:57:39.785 LISTENER ( PROCESS ) : updating 'cn=S-1-5-21-2124116158-320203473-397726588-1213,cn=sid,cn=temporary,cn=univention,dc=sas,dc=schein,dc=ig' command d 14.04.21 15:57:39.805 LISTENER ( PROCESS ) : updating 'cn=S-1-5-21-2124116158-320203473-397726588-1214,cn=sid,cn=temporary,cn=univention,dc=sas,dc=schein,dc=ig' command a 14.04.21 15:57:39.821 LISTENER ( PROCESS ) : updating 'cn=S-1-5-21-2124116158-320203473-397726588-1214,cn=sid,cn=temporary,cn=univention,dc=sas,dc=schein,dc=ig' command d 14.04.21 15:57:39.843 LISTENER ( PROCESS ) : updating 'cn=S-1-5-21-2124116158-320203473-397726588-1215,cn=sid,cn=temporary,cn=univention,dc=sas,dc=schein,dc=ig' command a 14.04.21 15:57:39.859 LISTENER ( PROCESS ) : updating 'cn=S-1-5-21-2124116158-320203473-397726588-1215,cn=sid,cn=temporary,cn=univention,dc=sas,dc=schein,dc=ig' command d 14.04.21 15:57:39.893 LISTENER ( PROCESS ) : updating 'cn=S-1-5-21-2124116158-320203473-397726588-1216,cn=sid,cn=temporary,cn=univention,dc=sas,dc=schein,dc=ig' command a 14.04.21 15:57:39.910 LISTENER ( PROCESS ) : updating 'cn=S-1-5-21-2124116158-320203473-397726588-1216,cn=sid,cn=temporary,cn=univention,dc=sas,dc=schein,dc=ig' command d 14.04.21 15:57:39.942 LISTENER ( PROCESS ) : updating 'cn=S-1-5-21-2124116158-320203473-397726588-1217,cn=sid,cn=temporary,cn=univention,dc=sas,dc=schein,dc=ig' command a 14.04.21 15:57:39.959 LISTENER ( PROCESS ) : updating 'cn=S-1-5-21-2124116158-320203473-397726588-1217,cn=sid,cn=temporary,cn=univention,dc=sas,dc=schein,dc=ig' command d 14.04.21 15:57:39.985 LISTENER ( PROCESS ) : updating 'cn=S-1-5-21-2124116158-320203473-397726588-1218,cn=sid,cn=temporary,cn=univention,dc=sas,dc=schein,dc=ig' command a 14.04.21 15:57:40.000 LISTENER ( PROCESS ) : updating 'cn=S-1-5-21-2124116158-320203473-397726588-1218,cn=sid,cn=temporary,cn=univention,dc=sas,dc=schein,dc=ig' command d 14.04.21 15:57:40.017 LISTENER ( PROCESS ) : updating 'cn=S-1-5-21-2124116158-320203473-397726588-1219,cn=sid,cn=temporary,cn=univention,dc=sas,dc=schein,dc=ig' command a 14.04.21 15:57:40.028 LISTENER ( PROCESS ) : updating 'cn=S-1-5-21-2124116158-320203473-397726588-1219,cn=sid,cn=temporary,cn=univention,dc=sas,dc=schein,dc=ig' command d 14.04.21 15:57:40.045 LISTENER ( PROCESS ) : updating 'cn=S-1-5-21-2124116158-320203473-397726588-1220,cn=sid,cn=temporary,cn=univention,dc=sas,dc=schein,dc=ig' command a 14.04.21 15:57:40.063 LISTENER ( PROCESS ) : updating 'cn=S-1-5-21-2124116158-320203473-397726588-1220,cn=sid,cn=temporary,cn=univention,dc=sas,dc=schein,dc=ig' command d 14.04.21 15:57:40.089 LISTENER ( PROCESS ) : updating 'cn=S-1-5-21-2124116158-320203473-397726588-1221,cn=sid,cn=temporary,cn=univention,dc=sas,dc=schein,dc=ig' command a 14.04.21 15:57:40.113 LISTENER ( PROCESS ) : updating 'cn=S-1-5-21-2124116158-320203473-397726588-1221,cn=sid,cn=temporary,cn=univention,dc=sas,dc=schein,dc=ig' command d 14.04.21 15:57:40.138 LISTENER ( PROCESS ) : updating 'cn=S-1-5-21-2124116158-320203473-397726588-1222,cn=sid,cn=temporary,cn=univention,dc=sas,dc=schein,dc=ig' command a 14.04.21 15:57:40.163 LISTENER ( PROCESS ) : updating 'cn=S-1-5-21-2124116158-320203473-397726588-1222,cn=sid,cn=temporary,cn=univention,dc=sas,dc=schein,dc=ig' command d 14.04.21 15:57:40.176 LISTENER ( PROCESS ) : updating 'cn=S-1-5-21-2124116158-320203473-397726588-1223,cn=sid,cn=temporary,cn=univention,dc=sas,dc=schein,dc=ig' command a 14.04.21 15:57:40.214 LISTENER ( PROCESS ) : updating 'cn=S-1-5-21-2124116158-320203473-397726588-1223,cn=sid,cn=temporary,cn=univention,dc=sas,dc=schein,dc=ig' command d 14.04.21 15:57:40.235 LISTENER ( PROCESS ) : updating 'cn=S-1-5-21-2124116158-320203473-397726588-1224,cn=sid,cn=temporary,cn=univention,dc=sas,dc=schein,dc=ig' command a 14.04.21 15:57:40.256 LISTENER ( PROCESS ) : updating 'cn=S-1-5-21-2124116158-320203473-397726588-1224,cn=sid,cn=temporary,cn=univention,dc=sas,dc=schein,dc=ig' command d 14.04.21 15:57:40.271 LISTENER ( PROCESS ) : updating 'cn=S-1-5-21-2124116158-320203473-397726588-1225,cn=sid,cn=temporary,cn=univention,dc=sas,dc=schein,dc=ig' command a 14.04.21 15:57:40.294 LISTENER ( PROCESS ) : updating 'cn=S-1-5-21-2124116158-320203473-397726588-1225,cn=sid,cn=temporary,cn=univention,dc=sas,dc=schein,dc=ig' command d 14.04.21 15:57:40.323 LISTENER ( PROCESS ) : updating 'cn=S-1-5-21-2124116158-320203473-397726588-1226,cn=sid,cn=temporary,cn=univention,dc=sas,dc=schein,dc=ig' command a 14.04.21 15:57:40.346 LISTENER ( PROCESS ) : updating 'cn=S-1-5-21-2124116158-320203473-397726588-1226,cn=sid,cn=temporary,cn=univention,dc=sas,dc=schein,dc=ig' command d 14.04.21 15:57:40.361 LISTENER ( PROCESS ) : updating 'cn=S-1-5-21-2124116158-320203473-397726588-1227,cn=sid,cn=temporary,cn=univention,dc=sas,dc=schein,dc=ig' command a 14.04.21 15:57:40.382 LISTENER ( PROCESS ) : updating 'cn=S-1-5-21-2124116158-320203473-397726588-1227,cn=sid,cn=temporary,cn=univention,dc=sas,dc=schein,dc=ig' command d
To be clear about Comment 1: This aggravates issues * by filling up the cn=translog branch in OpenLDAP (/var/lib/univention-ldap/translog/data.mdb) * by taking up replication time in support recovery cases (e.g. when data.mdb has reached it's max size) * e.g. in case of repeated S4/AD-Connector sync_to_ucs rejects/retries, which causes temporary objects to get created and removed frequently
r19503 | Bug #48626: Ignore cn=temporary > - > + you broke the patch: the trailing white spaces are required! > ++ ad->ad_translog_ignore_temporary = strcasecmp( ch_strdup( argv[1] ), "true" ) == 0; using `ch_strdup()` introduces a memory leak? > ++ Debug( LDAP_DEBUG_TRACE, "OVER: It is an univention temporary operation\n", 0, 0, 0 ); will this fill up the log because it is printed every time? > ++ int ad_translog_ignore_temporary; Use `bool` after doing a `#include <stdbool.h>`?
I've applied your suggestions to openldap patch
(In reply to Iván.Delgado from comment #6) > I've applied your suggestions to openldap patch Please reference the SVN commits here. And please set an appropriate target milestone for this bug.
The directory tree cn=temporary,cn=univention, is now ignored during replication. This behavior can be enabled via the UCR variable ldap/translog-ignore-temporary. By default, this is deactivated. (Pending to update on univention-ldap) openldap/5.0-0-0-ucs/2.4.47+dfsg-3+deb10u6-errata5.0-1 r19503 | Bug #48626: Ignore cn=temporary r19504 | Bug #48626: Ignore cn=temporary r19505 | Bug #48626: Ignore cn=temporary
The behavior was modified to skip only temporal grandchildren or child that contain the character '\,' This behavior can be enabled via the UCR variable ldap/translog-ignore-temporary. By default, this is deactivated. (Pending to update on univention-ldap) openldap/5.0-0-0-ucs/2.4.47+dfsg-3+deb10u6-errata5.0-1 r19503 | Bug #48626: Ignore cn=temporary r19504 | Bug #48626: Ignore cn=temporary r19505 | Bug #48626: Ignore cn=temporary r19506 | Bug #48626: Skip temporal grandchildren
Re: Comment 5: > > ++ Debug( LDAP_DEBUG_TRACE, "OVER: It is an univention temporary operation\n", 0, 0, 0 ); > will this fill up the log because it is printed every time? At log level trace only. I've proposed to add the DN to make it more informative.
(In reply to Arvid Requate from comment #10) > Re: Comment 5: > > > > ++ Debug( LDAP_DEBUG_TRACE, "OVER: It is an univention temporary operation\n", 0, 0, 0 ); > > will this fill up the log because it is printed every time? > > At log level trace only. I've proposed to add the DN to make it more > informative. Re-reading "include/ldap_log.h" the message is only printed for "ldap/debug/level=trace", which is okay for me. Printing the DN might be nice but I do not care.
The behavior was modified to skip only temporal grandchildren or child that contain the character '\,' This behavior can be enabled via the UCR variable ldap/translog-ignore-temporary. By default, this is deactivated. (Pending to update on univention-ldap) openldap/5.0-0-0-ucs/2.4.47+dfsg-3+deb10u6-errata5.0-1 r19503 | Bug #48626: Ignore cn=temporary r19504 | Bug #48626: Ignore cn=temporary r19505 | Bug #48626: Ignore cn=temporary r19506 | Bug #48626: Skip temporal grandchildren r19509 | Bug #48626: Remove else branch in translog_config openldap: 2.4.47+dfsg-3+deb10u6A~5.0.0.202201251313
Looks pretty good in my quick functional test with the changed univention-ldap from you feature branch: 1) Creating a user without the new option: * 12 transactions in /var/lib/univention-ldap/notify/transaction With the new option: 4 transactions: 1359 uid=user1,dc=ucs50domain,dc=net a 1360 cn=uidNumber,cn=temporary,cn=univention,dc=ucs50domain,dc=net m 1361 cn=Domain Users,cn=groups,dc=ucs50domain,dc=net m 1362 uid=user1,dc=ucs50domain,dc=net m Please note that we still replicate the cn=uidNumber and cn=gidNumber containers themselves because they contain the counter of the uidNumber/gidNumber to support the UDM allocator and that should be synchronized to the UCS Backup Directory Nodes in preparation of a possible future backup-to-master operation. 2) Similarly for groups: Creating an (empty) group without the new option: * 11 transactions in /var/lib/univention-ldap/notify/transaction With the new option: 3 transactions: 1386 cn=group1,dc=ucs50domain,dc=net a 1387 cn=gidNumber,cn=temporary,cn=univention,dc=ucs50domain,dc=net m 1388 cn=group1,dc=ucs50domain,dc=net m
Now this behavior can be configurable using a UCR variable called `ldap/translog-ignore-temporary` After set this variable the administrator user should be executed `systemctl restart slapd` to restart the slapd service. e39332919b Bug #48626: univention-ldap 16.0.7-10A~5.0.0.202201270853 e86e95c41b Bug #48626: avidsory and changelog 6f6e7867d0 Bug #48626: New UCRV ldap/translog-ignore-temporary and it is use on slapd.conf univention-ldap: 16.0.7-10A~5.0.0.202201270853
Ok, nice, this works. I think we should add a test case to test/ucs-test/tests/10_ldap/ to help us avoid regressions in the future. You could e.g. use the crud-lock-object.sh script I privided earlier and check that those DNs don't end up in /var/lib/univention-ldap/notify/transaction or alternatively you could create a pytest there, where you create a group and a user and check that no other objects than the cn=uidNumber and cn=gidNumber objects from below cn=temporary appear in that file.
Currently Backup and Replica servers fail at setup because their local slapd is not running: Jan 28 00:34:08 backup093 slapd[684]: 61f32bf0 /etc/ldap/slapd.conf: line 69: unknown directive <translog-ignore-temporary> inside backend database definition. slapschema: bad configuration file!. Jan 28 00:34:08 backup093 systemd[1]: slapd.service: Control process exited, code=exited, status=1/FAILURE Jan 28 00:34:08 backup093 systemd[1]: slapd.service: Failed with result 'exit-code'. The line translog-ignore-temporary true needs to be moved down a little. Then, after a slapd restart, the configuration works.
Pre-dependency of slapd was updated in univention-ldap package 96153eda6b Bug #48626: fixup! bug number in debian changelog 3fcb612904 Bug #48687: univention-ldap 16.0.7-11A~5.0.0.202201281218 f37d0daab8 Bug #48687: adjust pre-dependency to new slapd version The bug number 48687 in the commits message is wrong, the correct bug number is 48626 univention-ldap: 16.0.7-11A~5.0.0.202201281218
Hm, The issue was not with the different versions of slapd and univention-ldap. On Backups and Replicas, the translog overlay is not activated. But since you set the default of the UCR variable to True, the slapd.conf looks like this: database mdb suffix "dc=autotest092,dc=local" translog-ignore-temporary true overlay k5pwd I would either change the default, so that the UCR variable is only set on primary servers in the postinst. +++ management/univention-ldap/debian/univention-ldap-server.univention-config-registry-variables @@ -16,7 +16,6 @@ ReadOnly=yes Description[de]=Diese Variable kontrolliert, ob temporäre LDAP Objekte vom translog Modul verarbeitet werden sollen. Standardmäßig ist dies aktiviert. Nach der Änderung muss 'systemctl restart slapd' aus Description[en]=This variable controls if temporary LDAP objects should be processed by 'translog' Modul. By default it is enabled. After setting it 'systemctl restart slapd' must be executed. Type=bool -Default=True Categories=service-ldap or change the ucr template so that the "ignore-translog-overlay is only printed if ldap/translogfile is set. if configRegistry.get('ldap/translogfile'): print("overlay\t\ttranslog") print("translog\t%s" % configRegistry['ldap/translogfile']) -if configRegistry.is_true('ldap/translog-ignore-temporary'): - print("translog-ignore-temporary\ttrue") + if configRegistry.is_true('ldap/translog-ignore-temporary'): + print("translog-ignore-temporary\ttrue")
Only set ucr variable ldap/translog-ignore-temporary on master. 1070b0daed Bug #48626: univention-ldap 16.0.7-14A~5.0.0.202202011154 efd7133a51 Bug #48626: Increase version in debian/changelog 2dabd34871 Bug #48626: Fixed up only set ucr ldap/translog-ignore-temporary on master univention-ldap 16.0.7-14A~5.0.0.202202011154
Verified: * Code review (we did the C coding part in a peer to peer way) * Package update * Re-Joining * Advisory 651f42ee2f | Advisory update to explain a bit more
<https://errata.software-univention.de/#/?erratum=5.0x209> <https://errata.software-univention.de/#/?erratum=5.0x214>