Univention Bugzilla – Bug 35334
Listener Assertion if missing entryDN in Cache
Last modified: 2015-07-03 14:09:27 CEST
Reported at 2014071021000555 + 2014070721000418 univention-directroy-listener/src/change.c 596 »···// 3. Update entryDN 597 »···cache_entry_set1(&trans->cur.cache, "entryDN", current_dn); The function is only called during a move to update the DN of the cache_entry. The assertion is triggered, when the cache_entry does not have an entry for "entryDN", which all LDAP entries have. Might be a very old cache entry, as storing the operational attributes in the cache was AFAIK added at a later point in time. After stopping the listener a "univention-directory-listener-dump" could be used if there are other entries without an entryDN. Invalidating and re-building the cache should fix the problem. ... As this breaks the replication we should handle this another way perhaps.
It happend again weeks after a re-join.... so its not related to "old" cache entries or something like that...
Listener cache available at ticket - but I don't see any object with missing entryDN...
Happend again at #2014100821000348: on a Member (UCS 3.2-2 Errata 178). We will update to latest errata on Monday.
Is https://forge.univention.org/bugzilla3/show_bug.cgi?id=34013 possibly a fix?
(In reply to Tim Petersen from comment #4) > Is https://forge.univention.org/bugzilla3/show_bug.cgi?id=34013 possibly a > fix? unlikely.
Reported again 2015031821000073: One 3.2-2 memberserver and one 3.2-4 memberserver
Created attachment 6773 [details] Add entryDN if missing The attached patch adds the missing entryDN if it is missing (it never should). We should probably add an "emergency dump" before doing so to print the DN and the current state of that cache entry. If that error happens again: 1. Run "/usr/share/univention-directory-listener/get_notifier_id.py" to get the latest ID from the Univention Directory Notifier. 2. Run "cat /var/lib/univention-directory-listener/notifier_id" to get the latest ID from the Univention Directory Listener. 3. Run "sed -ne '/^XXXXX /,+10p' /var/lib/univention-ldap/notify/transaction" on the Master with XXXXX replaced by the ID from the Listener (step 2) to get the list of transactions the Listener should process next. 4. Use "univention-directory-listener-dump -O ./listener.dump" to dump the Listener Cache into a file. To temporary fix the problem run the following command: - On a DC Backup or DC Slave: "univention-directory-listener-ctrl resync replication" - on a Member-Server: "univention-join"
Regarding Ticket #2014070721000418 comment 12: > tar xfO listener_cache.tar.gz listener_cache.txt|ldapsearch-decode64|egrep '^(dn|entryDN):'|uniq -f 1 -i -u shows no discrepancy between "dn" and "entryDN" except several cases where the upper-/lower-case writing is different. In previous versions of the Listener that was a problem. The supplied cache file no longer shows such entries, but perhaps that should be considered as well.
Happend in our internal Jenkins Test on a S4-Master: <http://jenkins.knut.univention.de:8080/job/UCS-3.2/job/UCS-3.2-5/job/Autotest%20MultiEnv/SambaVersion=s4,Systemrolle=master/30/console> # /usr/share/univention-directory-listener/get_notifier_id.py 18995 # cat /var/lib/univention-directory-listener/notifier_id ; echo 18317 # sed -ne "/^$XXX /,+10p" /var/lib/univention-ldap/notify/transaction 18316 cn=kye44cyfof,cn=printers,dc=autotest091,dc=local m 18317 cn=kye44cyfof,cn=printers,dc=autotest091,dc=local d 18318 uid=jogz0zz5fo,cn=ŵnvü#ûüω?ĵ,dc=autotest091,dc=local r 18319 uid=jogz0zz5fo,cn=ŵnvü#ûüω?ĵ,dc=autotest091,dc=local a 18320 uid=jogz0zz5fo,cn=ŵnvü#ûüω?ĵ,dc=autotest091,dc=local r 18321 uid=jogz0zz5fo,cn=ŵnvü#ûüω?ĵ,dc=autotest091,dc=local a 18322 cn=S-1-5-21-3144399628-3514197741-1933986589-2370,cn=sid,cn=temporary,cn=univention,dc=autotest091,dc=local a 18323 uid=39wbp8e2e0,cn=424fpjvy63,dc=autotest091,dc=local m 18324 cn=S-1-5-21-3144399628-3514197741-1933986589-2370,cn=sid,cn=temporary,cn=univention,dc=autotest091,dc=local d 18325 cn=S-1-5-21-3144399628-3514197741-1933986589-2365,cn=sid,cn=temporary,cn=univention,dc=autotest091,dc=local a 18326 uid=3bdh8ithu7,ou=ab9fz07m3e,dc=autotest091,dc=local m 18327 cn=S-1-5-21-3144399628-3514197741-1933986589-2365,cn=sid,cn=temporary,cn=univention,dc=autotest091,dc=local d # sed -ne "/^dn: uid=jogz0zz5fo/,/^$/p" dump dn: uid=jogz0zz5fo,cn=ŵnvü#ûüΩ?ĵ,dc=autotest091,dc=local krb5PrincipalName: jogz0zz5fo@AUTOTEST091.LOCAL objectClass: top objectClass: person objectClass: univentionPWHistory objectClass: posixAccount objectClass: shadowAccount objectClass: univentionMail objectClass: sambaSamAccount objectClass: organizationalPerson objectClass: inetOrgPerson objectClass: krb5Principal objectClass: krb5KDCEntry objectClass: univentionObject uidNumber: 3883 sambaAcctFlags:: W1UgICAgICAgICAgXQ== sambaPasswordHistory: 0FC837D8BD08D28A8199A530EDD094038191645EB6E74849D8BF54E511826A43 krb5MaxLife: 86400 cn:: cTg2YXQ5cnFvdSBiNG03eWYwam52 userPassword: {crypt}$6$aY.QpzplJaOi2p8Q$Jknoo7jM1uhr15WnzkG73uSndwVAbT/63Q0ju28SYDoIzXIjHvq3LgCqtSOTNYfGt7WFsqMWEHjXRxIkyfhK8/ krb5Key:: MFWhKzApoAMCARKhIgQgsyS3est8she2ImZGExPONk5hwPhVQ4kzWG4XFQzigTWiJjAkoAMCAQOhHQQbQVVUT1RFU1QwOTEuTE9DQUxqb2d6MHp6NWZv krb5Key:: MEWhGzAZoAMCARGhEgQQ6I/dPlIku4uY7B4MT1t09qImMCSgAwIBA6EdBBtBVVRPVEVTVDA5MS5MT0NBTGpvZ3oweno1Zm8= krb5Key:: ME2hIzAhoAMCARChGgQYsJvvpJTmBEz3bQ4l8epXsMRU/aFXsIyeoiYwJKADAgEDoR0EG0FVVE9URVNUMDkxLkxPQ0FMam9nejB6ejVmbw== krb5Key:: MEWhGzAZoAMCARehEgQQyqEjnUTaft+Sa8459cZdD6ImMCSgAwIBA6EdBBtBVVRPVEVTVDA5MS5MT0NBTGpvZ3oweno1Zm8= krb5Key:: MD2hEzARoAMCAQOhCgQIzh+ROIp8syaiJjAkoAMCAQOhHQQbQVVUT1RFU1QwOTEuTE9DQUxqb2d6MHp6NWZv krb5Key:: MD2hEzARoAMCAQKhCgQIzh+ROIp8syaiJjAkoAMCAQOhHQQbQVVUT1RFU1QwOTEuTE9DQUxqb2d6MHp6NWZv krb5Key:: MD2hEzARoAMCAQGhCgQIzh+ROIp8syaiJjAkoAMCAQOhHQQbQVVUT1RFU1QwOTEuTE9DQUxqb2d6MHp6NWZv krb5MaxRenew: 604800 krb5KeyVersionNumber: 1 loginShell: /bin/bash univentionObjectType: users/user krb5KDCFlags: 126 sambaPwdLastSet: 1427094804 sambaNTPassword: CAA1239D44DA7EDF926BCE39F5C65D0F displayName:: cTg2YXQ5cnFvdSBiNG03eWYwam52 sambaSID: S-1-4-3883 gecos:: cTg2YXQ5cnFvdSBiNG03eWYwam52 sn: b4m7yf0jnv pwhistory: $6$CEfPfC7ZpZ7rQCGC$4gJ5ku/vKK9CN6cWUDWv7wtqchy0uz5Z21mX8refQW/m1R5sPWR1RD2RAWOCQNP79amaEi83m8e8iEuuZNALZ. homeDirectory: /home/jogz0zz5fo givenName: q86at9rqou structuralObjectClass: inetOrgPerson entryUUID: d6f488d6-6577-1034-8381-bd8822c5191d creatorsName: cn=admin,dc=autotest091,dc=local createTimestamp: 20150323071324Z gidNumber: 5001 sambaPrimaryGroupSID: S-1-5-21-3144399628-3514197741-1933986589-513 uid: jogz0zz5fo entryCSN: 20150323071324.976288Z#000000#000#000000 modifiersName: cn=admin,dc=autotest091,dc=local modifyTimestamp: 20150323071324Z entryDN:: dWlkPWpvZ3oweno1Zm8sY249xbVudsO8I8O7w7zOqT/EtSxkYz1hdXRvdGVzdDA5MSxkYz1sb2NhbA== subschemaSubentry: cn=Subschema hasSubordinates: FALSE listenerModule: samba4-idmap listenerModule: well-known-sid-name-mapping listenerModule: s4-connector listenerModule: faillog listenerModule: cyrus # ucr set listener/debug/level=4 # tail -f /var/log/univention/listener.log > LISTENER ( ALL ) : no cache entry found for uid=jogz0zz5fo,cn=ŵnvü#ûüω?ĵ,dc=autotest091,dc=local > LISTENER ( INFO ) : updating 'uid=jogz0zz5fo,cn=ŵnvü#ûüω?ĵ,dc=autotest091,dc=local' command a univention-directory-listener: cache_entry.c:533: cache_entry_set1: Assertion `i < entry->attribute_count' failed. # ucr set repository/online/unmaintained=yes repository/online/sources=yes # apt-get -qq update # apt-get -qq install libc6-dbg univention-directory-listener-dbg gdb dpkg-dev # apt-get source univention-directory-listener # cd univention-directory-listener-8.0.4/src/ # gdb --args /usr/sbin/univention-directory-listener -F -b "$(ucr get ldap/base)" -m /usr/lib/univention-directory-listener/system -c /var/lib/univention-directory-listener -d 3 -x -ZZ -D "cn=admin,"$(ucr get ldap/base)" -y /etc/ldap.secret (gdb) run (gdb) bt #0 0x00007ffff6ce0ed5 in *__GI_raise (sig=<value optimized out>) at ../nptl/sysdeps/unix/sysv/linux/raise.c:64 #1 0x00007ffff6ce3ce0 in *__GI_abort () at abort.c:92 #2 0x00007ffff6cda021 in *__GI___assert_fail (assertion=0x412a57 "i < entry->attribute_count", file=<value optimized out>, line=533, function=0x412ac0 "cache_entry_set1") at assert.c:81 #3 0x000000000040a9de in cache_entry_set1 (entry=0x7fffffffe370, key=0x413080 "entryDN", value=0x100cd10 "uid=jogz0zz5fo,cn=ŵnvü#ûüω?ĵ,dc=autotest091,dc=local") at cache_entry.c:533 #4 0x000000000040d859 in process_move (trans=0x7fffffffe340) at change.c:597 #5 0x000000000040db32 in change_update_cache (trans=0x7fffffffe340) at change.c:654 #6 0x000000000040e143 in change_update_dn (trans=0x7fffffffe340) at change.c:765 #7 0x0000000000404c6e in notifier_listen (lp=0x618150, kp=0x0, write_transaction_file=0, lp_local=0x6181d0) at notifier.c:176 #8 0x0000000000404763 in main (argc=16, argv=0x7fffffffe608) at main.c:612 (gdb) frame 4 (gdb) print *trans $3 = {lp = 0x618150, lp_local = 0x6181d0, ldap = 0x101d0d0, cur = {notify = {id = 18319, dn = 0x100cd10 "uid=jogz0zz5fo,cn=ŵnvü#ûüω?ĵ,dc=autotest091,dc=local", command = 97 'a'}, cache = { attributes = 0x0, attribute_count = 0, modules = 0x0, module_count = 0}, ldap_dn = 0x11cd810 "uid=jogz0zz5fo,cn=ŵnvü#ûüΩ?ĵ,dc=autotest091,dc=local", uuid = 0x0}, prev = { notify = {id = 18318, dn = 0x10d8290 "uid=jogz0zz5fo,cn=ŵnvü#ûüω?ĵ,dc=autotest091,dc=local", command = 114 'r'}, cache = {attributes = 0x0, attribute_count = 0, modules = 0x0, module_count = 0}, ldap_dn = 0xf87870 "uid=jogz0zz5fo,cn=ŵnvü#ûüΩ?ĵ,dc=autotest091,dc=local", uuid = 0x0}} (gdb) print trans->prev.notify.dn $4 = 0x10d8290 "uid=jogz0zz5fo,cn=ŵnvü#ûüω?ĵ,dc=autotest091,dc=local" (gdb) print trans->cur.notify.dn $5 = 0x100cd10 "uid=jogz0zz5fo,cn=ŵnvü#ûüω?ĵ,dc=autotest091,dc=local" (gdb) print trans->cur.ldap_dn $6 = 0x11cd810 "uid=jogz0zz5fo,cn=ŵnvü#ûüΩ?ĵ,dc=autotest091,dc=local" ^ *captial Omega* vs *lower case omega* (gdb) call strcasecmp(trans->cur.notify.dn, trans->cur.ldap_dn) $7 = 1 (gdb) print final $8 = false The listener is using "strcasecmp()" internally, for which <http://pubs.opengroup.org/onlinepubs/007908775/xsh/strcasecmp.html> has this description: > In the POSIX locale, strcasecmp() and strncasecmp() do upper to lower conversions, then a byte comparison. > *The results are unspecified in other locales.* This is NOT mentioned in the Linux version of the manual page. FYI: 'tr' also only works on bytes: <http://en.wikipedia.org/wiki/Tr_%28Unix%29> Most versions of tr, including GNU tr and classic Unix tr, operate on single-byte characters and are not Unicode compliant. # univention-ldapsearch -LLLo ldif-wrap=no -b "uid=jogz0zz5fo,cn=ŵnvü#ûüΩ?ĵ,dc=autotest091,dc=local" dn entryDN | ldapsearch-decode64 dn: uid=jogz0zz5fo,cn=ŵnvü#ûüΩ?ĵ,dc=autotest091,dc=local entryDN: uid=jogz0zz5fo,cn=ŵnvü#ûüΩ?ĵ,dc=autotest091,dc=local # univention-ldapsearch -LLLo ldif-wrap=no -b "uid=jogz0zz5fo,cn=ŵnvü#ûüω?ĵ,dc=autotest091,dc=local" dn entryDN | ldapsearch-decode64 dn: uid=jogz0zz5fo,cn=ŵnvü#ûüΩ?ĵ,dc=autotest091,dc=local entryDN: uid=jogz0zz5fo,cn=ŵnvü#ûüΩ?ĵ,dc=autotest091,dc=local The entry is stored in the upper-case version inside OpenLDAP and the Listener Cache, but the notifier gets the lower-case version (trans->cur.notify.d). > change.c:709 rv = cache_get_entry_lower_upper(trans->cur.notify.dn, &trans->cur.cache); then doesn't find the right entry: cache_get_entry_lower_upper() is calling _convert_to_lower(), which converts the string on a byte-by-byte basis to lower-case, which does not work with UTF-8, as within the Greek alphabet the distance between 'ω' and 'Ω' is too large and causes an increment in the previous byte: # echo -n äÄωΩ | recode UTF-8..dump UCS2 Mne Beschreibung 00E4 a: latin small letter a with diaeresis 00C4 A: latin capital letter a with diaeresis 03C9 w* greek small letter omega 03A9 W* greek capital letter omega $ echo -n äÄ | xxd -g 1 0000000: c3 a4 c3 84 .... $ echo -n ωΩ | xxd -g 1 0000000: cf 89 ce a9 .... FYI: Please note that case-conversion is very fragile and there are event characters, for which no equivalent upper-/lower-case character exists (German szlig or Turkish <http://en.wikipedia.org/wiki/Dotted_and_dotless_I>
Uh, I guess that's my fault.. > FYI: Please note that case-conversion is very fragile and there are event characters, for which no equivalent upper-/lower-case character exists (German szlig or Turkish <http://en.wikipedia.org/wiki/Dotted_and_dotless_I> I would expect a "map to self" for these characters? Like digits. Doesn't matter as long as the mapping is deterministic and bijective.
(In reply to Arvid Requate from comment #10) > Uh, I guess that's my fault.. No finger pointing here intended ... just FYI that case-conversion is not easy. It was my assumption to that strcasecmp() would work for non-POSIX-locales, too. > I would expect a "map to self" for these characters? Like digits. Doesn't > matter as long as the mapping is deterministic and bijective. No, it isn't bijective! See <http://en.wikipedia.org/wiki/Dotted_and_dotless_I#Implications_for_casing> and above: > Thus uppercasing then lowercasing, or vice versa, changes the letters.
S4,Master UCS-4.0-1 <http://jenkins.knut.univention.de:8080/job/UCS-4.0/job/UCS-4.0-1/job/Autotest%20MultiEnv/SambaVersion=s4,Systemrolle=master/77/> Listener-Log: dn: uid=8uswn0a2d6,cn=öfyω}_#½^ĉ,dc=AutoTest091,dc=local univention-directory-listener-dump: dn: uid=8uswn0a2d6,cn=öfyΩ}_#½^ĉ,dc=autotest091,dc=local krb5PrincipalName: 8uswn0a2d6@AUTOTEST091.LOCAL objectClass: top objectClass: person objectClass: univentionPWHistory objectClass: posixAccount objectClass: shadowAccount objectClass: univentionMail objectClass: sambaSamAccount objectClass: organizationalPerson objectClass: inetOrgPerson objectClass: krb5Principal objectClass: krb5KDCEntry objectClass: univentionObject uidNumber: 3640 sambaAcctFlags:: W1UgICAgICAgICAgXQ== sambaPasswordHistory: 41323A9C8F491957FA241683429E6A9402A08BDAF18EE288B61FE63E532E7713 krb5MaxLife: 86400 cn:: bW5hNWh0YTNubCBnaHFxbmwxZjNi userPassword: {crypt}$6$oxEPkLsozTfHsIEu$mTnNK3Av.z8eEqvDM2sc1Fgo9qTVZuuTN6x.l2mwtOyUlr1vSz0W5nVN646IbIB4DPhSu/i7.McuYMR8PSbpd/ krb5Key:: MFWhKzApoAMCARKhIgQg/EElxk8fIvM3oyQDMfRXUfHMChYXiDjmgW06es3INyaiJjAkoAMCAQOhHQQbQVVUT1RFU1QwOTEuTE9DQUw4dXN3bjBhMmQ2 krb5Key:: MEWhGzAZoAMCARGhEgQQA2ut/5NGAIkenlK8GbJ9DqImMCSgAwIBA6EdBBtBVVRPVEVTVDA5MS5MT0NBTDh1c3duMGEyZDY= krb5Key:: ME2hIzAhoAMCARChGgQYxASwSverZDHLLHWuFdN1lATTp3ngSrWRoiYwJKADAgEDoR0EG0FVVE9URVNUMDkxLkxPQ0FMOHVzd24wYTJkNg== krb5Key:: MEWhGzAZoAMCARehEgQQyqEjnUTaft+Sa8459cZdD6ImMCSgAwIBA6EdBBtBVVRPVEVTVDA5MS5MT0NBTDh1c3duMGEyZDY= krb5Key:: MD2hEzARoAMCAQOhCgQIgFfNisGFRn+iJjAkoAMCAQOhHQQbQVVUT1RFU1QwOTEuTE9DQUw4dXN3bjBhMmQ2 krb5Key:: MD2hEzARoAMCAQKhCgQIgFfNisGFRn+iJjAkoAMCAQOhHQQbQVVUT1RFU1QwOTEuTE9DQUw4dXN3bjBhMmQ2 krb5Key:: MD2hEzARoAMCAQGhCgQIgFfNisGFRn+iJjAkoAMCAQOhHQQbQVVUT1RFU1QwOTEuTE9DQUw4dXN3bjBhMmQ2 krb5MaxRenew: 604800 krb5KeyVersionNumber: 1 loginShell: /bin/bash univentionObjectType: users/user krb5KDCFlags: 126 sambaPwdLastSet: 1429684381 sambaNTPassword: CAA1239D44DA7EDF926BCE39F5C65D0F displayName:: bW5hNWh0YTNubCBnaHFxbmwxZjNi sambaSID: S-1-4-3640 gecos:: bW5hNWh0YTNubCBnaHFxbmwxZjNi sn: ghqqnl1f3b pwhistory: $6$KfoTSXnazEqaETWk$9QAVoniQzxq9wpvKhxLEIDqbuEsRJn1YUq4l2XOK0xQCF/ZXhyBMOm805yYcnrbeX0VG4W5g2oejXqTEnPtO5/ homeDirectory: /home/8uswn0a2d6 givenName: mna5hta3nl structuralObjectClass: inetOrgPerson entryUUID: 2b6cadcc-7d05-1034-9f0d-c173d04ef963 creatorsName: cn=admin,dc=AutoTest091,dc=local createTimestamp: 20150422063302Z gidNumber: 5001 sambaPrimaryGroupSID: S-1-5-21-855005882-547714306-3646502573-513 uid: 8uswn0a2d6 entryCSN: 20150422063302.514354Z#000000#000#000000 modifiersName: cn=admin,dc=AutoTest091,dc=local modifyTimestamp: 20150422063302Z entryDN:: dWlkPTh1c3duMGEyZDYsY249w7Zmec6pfV8jwr1exIksZGM9QXV0b1Rlc3QwOTEsZGM9bG9jYWw= subschemaSubentry: cn=Subschema hasSubordinates: FALSE listenerModule: well-known-sid-name-mapping listenerModule: faillog listenerModule: samba4-idmap listenerModule: s4-connector listenerModule: cyrus
Maybe have a look at <http://userguide.icu-project.org/transforms/casemappings>? Or see openldap-2.4.40/libraries/liblunicode/ucstr.c UTF8bvnormcmp() OpenLDAP internally uses UTF8bvnormalize() from the same file to implement case-inexact-matching: ./servers/slapd/schema_init.c:1815 flags = SLAP_MR_ASSOCIATED( mr, slap_schema.si_mr_caseExactMatch ) ? LDAP_UTF8_NOCASEFOLD : LDAP_UTF8_CASEFOLD; flags |= ( ( use & SLAP_MR_EQUALITY_APPROX ) == SLAP_MR_EQUALITY_APPROX ) ? LDAP_UTF8_APPROX : 0; val = UTF8bvnormalize( val, &tmp, flags, ctx );
r61204 | Bug #35334 Listener: Fix entryDN assertion The assertion was replaced by adding the entryUUID if it is missing. r61210 | Bug #35334 Listener: Fix overflow in utf8 conversion r61203 | Bug #35334 Listener: Fix case normalization There was a bug when the container name uses upper-case non-ASCII characters, but the lower-case variant was used to create the subordinate entries. In that case the Lisener did not find the parent container: For "aΩ" mixedcase was false as the only ASCII-character is lower-case. strcasecmp() is replaced with strcmp(utf8_lower()), which is what slapd uses internally (when case is ignored). OpenLDAP internally uses liblunicode, which is not public; the closest match is "libicu". r61211 | Bug #35334 Listener: Fix memory leaks r61206 | Bug #35334 Listener: unit tests r61205 | Bug #35334 Listener: unit tests r61201 | Bug #35334 Listener: Fix test requiring replication r61200 | Bug #35334 Listener: Copyright 2015 The unit tests were updated - they are still not executed automatically! Package: univention-directory-listener Version: 9.0.2-4.267.201506121103 Branch: ucs_4.0-0 Scope: errata4.0-2 r61212 | Bug #35334, Bug #32819 Listener: YAML 2015-06-12-univention-directory-listener.yaml (In reply to Philipp Hahn from comment #8) > 18318 uid=jogz0zz5fo,cn=ŵnvü#ûüω?ĵ,dc=autotest091,dc=local r > 18319 uid=jogz0zz5fo,cn=ŵnvü#ûüω?ĵ,dc=autotest091,dc=local a > 18320 uid=jogz0zz5fo,cn=ŵnvü#ûüω?ĵ,dc=autotest091,dc=local r > 18321 uid=jogz0zz5fo,cn=ŵnvü#ûüω?ĵ,dc=autotest091,dc=local a I have no explanation for that strange sequence, but the listener should handle this fine with the two changes from above.
Again with the *old* version: <http://jenkins.knut.univention.de:8080/job/UCS-4.0/job/UCS-4.0-2/job/Autotest%20MultiEnv/SambaVersion=s4,Systemrolle=master/32/> # ps axf ##### this is the currently running test ##### 29_dns_host_record_modification_set_mx # dpkg-query -W univention-directory-listener univention-directory-listener 9.0.2-1.239.201409081755 # tail /var/log/univention/listener.log 12.06.15 12:48:17.885 LISTENER ( ALL ) : no cache entry found for uid=n76xqmhdkf,cn=ŷka{:ω#û?4,dc=AutoTest091,dc=local 12.06.15 12:48:17.885 LISTENER ( ALL ) : updating by DN uid=n76xqmhdkf,cn=ŷka{:ω#û?4,dc=AutoTest091,dc=local # grep -F 'cn=ŷka{' /var/log/univention/listener.log 18607 uid=n76xqmhdkf,cn=ŷka{:ω#û?4,dc=AutoTest091,dc=local r 12.06.15 12:48:17.884 LISTENER ( INFO ) : notifier returned = id: 18607 dn: uid=n76xqmhdkf,cn=ŷka{:ω#û?4,dc=AutoTest091,dc=local cmd: r 12.06.15 12:48:17.884 LISTENER ( INFO ) : updating 'uid=n76xqmhdkf,cn=ŷka{:ω#û?4,dc=AutoTest091,dc=local' command r 12.06.15 12:48:17.884 LISTENER ( ALL ) : no cache entry found for uid=n76xqmhdkf,cn=ŷka{:ω#û?4,dc=autotest091,dc=local 12.06.15 12:48:17.884 LISTENER ( ALL ) : no cache entry found for uid=n76xqmhdkf,cn=ŷka{:ω#û?4,dc=AutoTest091,dc=local 12.06.15 12:48:17.884 LISTENER ( ALL ) : updating by DN uid=n76xqmhdkf,cn=ŷka{:ω#û?4,dc=AutoTest091,dc=local 18608 uid=n76xqmhdkf,cn=ŷka{:ω#û?4,dc=AutoTest091,dc=local a 12.06.15 12:48:17.885 LISTENER ( INFO ) : notifier returned = id: 18608 dn: uid=n76xqmhdkf,cn=ŷka{:ω#û?4,dc=AutoTest091,dc=local cmd: a 12.06.15 12:48:17.885 LISTENER ( INFO ) : updating 'uid=n76xqmhdkf,cn=ŷka{:ω#û?4,dc=AutoTest091,dc=local' command a 12.06.15 12:48:17.885 LISTENER ( ALL ) : no cache entry found for uid=n76xqmhdkf,cn=ŷka{:ω#û?4,dc=autotest091,dc=local 12.06.15 12:48:17.885 LISTENER ( ALL ) : no cache entry found for uid=n76xqmhdkf,cn=ŷka{:ω#û?4,dc=AutoTest091,dc=local 12.06.15 12:48:17.885 LISTENER ( ALL ) : updating by DN uid=n76xqmhdkf,cn=ŷka{:ω#û?4,dc=AutoTest091,dc=local 18607 uid=n76xqmhdkf,cn=ŷka{:ω#û?4,dc=AutoTest091,dc=local r 12.06.15 12:49:20.095 LISTENER ( INFO ) : notifier returned = id: 18607 dn: uid=n76xqmhdkf,cn=ŷka{:ω#û?4,dc=AutoTest091,dc=local cmd: r 12.06.15 12:49:20.095 LISTENER ( INFO ) : updating 'uid=n76xqmhdkf,cn=ŷka{:ω#û?4,dc=AutoTest091,dc=local' command r 12.06.15 12:49:20.095 LISTENER ( ALL ) : no cache entry found for uid=n76xqmhdkf,cn=ŷka{:ω#û?4,dc=autotest091,dc=local 12.06.15 12:49:20.095 LISTENER ( ALL ) : no cache entry found for uid=n76xqmhdkf,cn=ŷka{:ω#û?4,dc=AutoTest091,dc=local 12.06.15 12:49:20.095 LISTENER ( ALL ) : updating by DN uid=n76xqmhdkf,cn=ŷka{:ω#û?4,dc=AutoTest091,dc=local 18608 uid=n76xqmhdkf,cn=ŷka{:ω#û?4,dc=AutoTest091,dc=local a 12.06.15 12:49:20.108 LISTENER ( INFO ) : notifier returned = id: 18608 dn: uid=n76xqmhdkf,cn=ŷka{:ω#û?4,dc=AutoTest091,dc=local cmd: a 12.06.15 12:49:20.108 LISTENER ( INFO ) : updating 'uid=n76xqmhdkf,cn=ŷka{:ω#û?4,dc=AutoTest091,dc=local' command a 12.06.15 12:49:20.108 LISTENER ( ALL ) : no cache entry found for uid=n76xqmhdkf,cn=ŷka{:ω#û?4,dc=autotest091,dc=local 12.06.15 12:49:20.108 LISTENER ( ALL ) : no cache entry found for uid=n76xqmhdkf,cn=ŷka{:ω#û?4,dc=AutoTest091,dc=local 12.06.15 12:49:20.108 LISTENER ( ALL ) : updating by DN uid=n76xqmhdkf,cn=ŷka{:ω#û?4,dc=AutoTest091,dc=local # sed -ne '/^18607 /,+10p' /var/lib/univention-ldap/notify/transaction 18607 uid=n76xqmhdkf,cn=ŷka{:ω#û?4,dc=AutoTest091,dc=local r 18608 uid=n76xqmhdkf,cn=ŷka{:ω#û?4,dc=AutoTest091,dc=local a 18609 uid=n76xqmhdkf,cn=ŷka{:ω#û?4,dc=AutoTest091,dc=local r 18610 uid=n76xqmhdkf,cn=ŷka{:ω#û?4,dc=AutoTest091,dc=local a 18611 cn=tmyzlpjnjs,cn=printers,dc=AutoTest091,dc=local m 18612 cn=tmyzlpjnjs,cn=printers,dc=AutoTest091,dc=local d 18613 cn=mdcj56v10c,cn=printers,dc=AutoTest091,dc=local a 18614 cn=mdcj56v10c,cn=printers,dc=AutoTest091,dc=local d 18615 cn=vlqe904nni,cn=printers,dc=AutoTest091,dc=local a 18616 cn=vlqe904nni,cn=printers,dc=AutoTest091,dc=local d 18617 cn=yhpzprdomo,dc=AutoTest091,dc=local a # grep -B7 -A17 n76xqmhdkf ucs-test.log ##### this is the test which crated the probelmatic container ##### *** BEGIN *** ['/usr/bin/python', '16_container_cn_rename_with_special_characters'] *** *** 63_udm-containers/16_container_cn_rename_with_special_characters *** Rename a container/cn with subobjects *** *** START TIME: 2015-06-12 04:37:52 *** Creating container/cn object with {'name': '\xc3\x9fdz\xc3\xaa/-\xc3\xb4\xc3\xa2\xc3\xb4\xc3\xa2'} Waiting for replication: OK: replication complete (nid=18403 lid=18403) Done: replication complete. Creating users/user object with {'username': 'n76xqmhdkf', 'position': 'cn=\xc3\x9fdz\xc3\xaa/-\xc3\xb4\xc3\xa2\xc3\xb4\xc3\xa2,dc=AutoTest091,dc=local', 'password': 'univention', 'firstname': 'obn5x4cgyj', 'lastname': 'ggiis8lanj'} Waiting for replication: OK: replication complete (nid=18412 lid=18412) Done: replication complete. Modifying container/cn object with {'dn': 'cn=\xc3\x9fdz\xc3\xaa/-\xc3\xb4\xc3\xa2\xc3\xb4\xc3\xa2,dc=AutoTest091,dc=local', 'name': '\xc5\xb7ka{:\xce\xa9#\xc3\xbb?4'} Waiting for replication: OK: replication complete (nid=18417 lid=18417) Done: replication complete. Performing UCSTestUDM cleanup... UCSTestUDM cleanup done *** END TIME: 2015-06-12 04:37:55 *** *** TEST DURATION (H:MM:SS.ms): 0:00:02.942433 *** *** END *** 0 *** *** BEGIN *** ['/usr/bin/python', '17_container_cn_rename_uppercase'] *** *** 63_udm-containers/17_container_cn_rename_uppercase *** Rename a container/cn with subobjects from lower to upper case *** *** START TIME: 2015-06-12 04:37:55 *** Creating container/cn object with {'position': 'dc=AutoTest091,dc=local', 'name': 's0l8g420yh'} # dn=$(python -c "print '\xc3\x9fdz\xc3\xaa/-\xc3\xb4\xc3\xa2\xc3\xb4\xc3\xa2'");sed -nre "\+$dn.* a+,\+$dn.* d+p" /var/lib/univention-ldap/notify/transaction 18403 cn=ßdzê/-ôâôâ,dc=AutoTest091,dc=local a 18404 cn=n76xqmhdkf,cn=uid,cn=temporary,cn=univention,dc=AutoTest091,dc=local a 18405 cn=3796,cn=uidNumber,cn=temporary,cn=univention,dc=AutoTest091,dc=local a 18406 uid=n76xqmhdkf,cn=ßdzê/-ôâôâ,dc=AutoTest091,dc=local a 18407 cn=n76xqmhdkf,cn=uid,cn=temporary,cn=univention,dc=AutoTest091,dc=local d 18408 cn=uidNumber,cn=temporary,cn=univention,dc=AutoTest091,dc=local m 18409 cn=3796,cn=uidNumber,cn=temporary,cn=univention,dc=AutoTest091,dc=local d 18410 cn=Domain Users,cn=groups,dc=AutoTest091,dc=local m 18411 uid=n76xqmhdkf,cn=ßdzê/-ôâôâ,dc=AutoTest091,dc=local m 18412 uid=n76xqmhdkf,cn=ßdzê/-ôâôâ,dc=AutoTest091,dc=local m 18413 cn=ŷka{:Ω#û?4,dc=AutoTest091,dc=local a 18414 uid=n76xqmhdkf,cn=ßdzê/-ôâôâ,dc=AutoTest091,dc=local r 18415 uid=n76xqmhdkf,cn=ŷka{:Ω#û?4,dc=AutoTest091,dc=local a 18416 cn=Domain Users,cn=groups,dc=AutoTest091,dc=local m 18417 cn=ßdzê/-ôâôâ,dc=AutoTest091,dc=local d # grep -Fi 'ŷka{:ω#û?4' /var/lib/univention-ldap/notify/transaction 18413 cn=ŷka{:Ω#û?4,dc=AutoTest091,dc=local a 18415 uid=n76xqmhdkf,cn=ŷka{:Ω#û?4,dc=AutoTest091,dc=local a 18607 uid=n76xqmhdkf,cn=ŷka{:ω#û?4,dc=AutoTest091,dc=local r 18608 uid=n76xqmhdkf,cn=ŷka{:ω#û?4,dc=AutoTest091,dc=local a 18609 uid=n76xqmhdkf,cn=ŷka{:ω#û?4,dc=AutoTest091,dc=local r 18610 uid=n76xqmhdkf,cn=ŷka{:ω#û?4,dc=AutoTest091,dc=local a Notice that the folder was created by 18413 with capital "Ω", while later in 18607 it is referenced with lower-case "ω". I still don't understand, why the folder is accessed again 200 transactions later. The test after "16_container_cn_rename_with_special_characters" is "17_container_cn_rename_uppercase", which created a folder named "s0l8g420yh" according to ucs-test.log # grep s0l8g420yh /var/lib/univention-ldap/notify/transaction 18418 cn=s0l8g420yh,dc=AutoTest091,dc=local a 18420 cn=s0l8g420yh,dc=AutoTest091,dc=local r Notice that in 18413 the folder is *a*dded without a previous *r*ename, because the old Lister does not find the cache entry for the old entry. Thus it's not a move but an add.
> I still don't understand, why the folder is accessed again 200 transactions later. Maybe the S4-Connector replicates back at that point? I added a simple ucs-test case tests/10_ldap/51listener_case_handling.
Advisory is ok, I have sent a suggestion for / question about the code via email.
r61325 | Bug #35334 Listener: Fix case normalization Using ucasemap() convert the "LATIN CAPITAL LETTER I WITH DOT ABOVE" (U+0130) to "LATIN SMALL LETTER I" + "diacritique point en chef", which is rendered like "i" but doesn't compare equal with it in OpenLDAP: # python -c 'print "\x69\x69\xcc\x87\xc4\xb1",' | recode u8..dump 0069 i latin small letter i 0069 i latin small letter i 0307 diacritique point en chef 0131 i. latin small letter i dotless As neither locale=NULL nor locale=NULL, nor U_FOLD_CASE_EXCLUDE_SPECIAL_I works, I've implemented my own lower casing version. Package: univention-directory-listener Version: 9.0.2-5.269.201506171450 Branch: ucs_4.0-0-errata4.0-2 Scope: errata4.0-2 r61326 | Bug #35334 Listener: Fix case normalization YAML 2015-06-12-univention-directory-listener.yaml
Ok, works. Advisory is also up to date.
<http://errata.univention.de/ucs/4.0/224.html>