Bug 53776 - 63_udm-containers.01_test_udm_containers.Test_ContainerCN.test_container_cn_rename_uppercase_rollback_with_special_characters broken for umlauts
63_udm-containers.01_test_udm_containers.Test_ContainerCN.test_container_cn_r...
Status: NEW
Product: UCS Test
Classification: Unclassified
Component: UDM
unspecified
Other Linux
: P5 normal (vote)
: ---
Assigned To: UMC maintainers
:
: 44853 47724 (view as bug list)
Depends on:
Blocks:
  Show dependency treegraph
 
Reported: 2021-09-13 10:15 CEST by Florian Best
Modified: 2021-09-15 12:38 CEST (History)
3 users (show)

See Also:
What kind of report is it?: Development Internal
What type of bug is this?: ---
Who will be affected by this bug?: ---
How will those affected feel about the bug?: ---
User Pain:
Enterprise Customer affected?:
School Customer affected?:
ISV affected?:
Waiting Support:
Flags outvoted (downgraded) after PO Review:
Ticket number:
Bug group (optional):
Max CVSS v3 score:


Attachments
Test output (24.02 KB, text/plain)
2021-09-14 21:26 CEST, Philipp Hahn
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Florian Best univentionstaff 2021-09-13 10:15:36 CEST
Fehlermeldung

univention.testing.utils.LDAPObjectNotFound: DN: cn=SSWV^}{$Ĵ´2,dc=autotest090,dc=local

Stacktrace

Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/univention/testing/utils.py", line 237, in __verify_ldap_object
    attr=expected_attr.keys()
  File "/usr/lib/python3/dist-packages/univention/uldap.py", line 208, in _decorated
    return func(self, *args, **kwargs)
  File "/usr/lib/python3/dist-packages/univention/uldap.py", line 516, in search
    res = self.lo.search_ext_s(base, ldap_scope, filter, attr, serverctrls=serverctrls, clientctrls=None, timeout=timeout, sizelimit=sizelimit)
  File "/usr/lib/python3/dist-packages/ldap/ldapobject.py", line 1259, in search_ext_s
    return self._apply_method_s(SimpleLDAPObject.search_ext_s,*args,**kwargs)
  File "/usr/lib/python3/dist-packages/ldap/ldapobject.py", line 1197, in _apply_method_s
    return func(self,*args,**kwargs)
  File "/usr/lib/python3/dist-packages/ldap/ldapobject.py", line 846, in search_ext_s
    return self.result(msgid,all=1,timeout=timeout)[1]
  File "/usr/lib/python3/dist-packages/ldap/ldapobject.py", line 738, in result
    resp_type, resp_data, resp_msgid = self.result2(msgid,all,timeout)
  File "/usr/lib/python3/dist-packages/ldap/ldapobject.py", line 742, in result2
    resp_type, resp_data, resp_msgid, resp_ctrls = self.result3(msgid,all,timeout)
  File "/usr/lib/python3/dist-packages/ldap/ldapobject.py", line 749, in result3
    resp_ctrl_classes=resp_ctrl_classes
  File "/usr/lib/python3/dist-packages/ldap/ldapobject.py", line 756, in result4
    ldap_result = self._ldap_call(self._l.result4,msgid,all,timeout,add_ctrls,add_intermediates,add_extop)
  File "/usr/lib/python3/dist-packages/ldap/ldapobject.py", line 329, in _ldap_call
    reraise(exc_type, exc_value, exc_traceback)
  File "/usr/lib/python3/dist-packages/ldap/compat.py", line 44, in reraise
    raise exc_value
  File "/usr/lib/python3/dist-packages/ldap/ldapobject.py", line 313, in _ldap_call
    result = func(*args,**kwargs)
ldap.NO_SUCH_OBJECT: {'desc': 'No such object', 'matched': 'dc=autotest090,dc=local'}

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/share/ucs-test/63_udm-containers/01_test_udm_containers.py", line 677, in test_container_cn_rename_uppercase_rollback_with_special_characters
    utils.verify_ldap_object(new_cn, should_exist=True)
  File "/usr/lib/python3/dist-packages/univention/testing/utils.py", line 225, in verify_ldap_object
    delay)
  File "/usr/lib/python3/dist-packages/univention/testing/utils.py", line 175, in retry_on_error
    six.reraise(*exc_info)
  File "/usr/lib/python3/dist-packages/six.py", line 693, in reraise
    raise value
  File "/usr/lib/python3/dist-packages/univention/testing/utils.py", line 166, in retry_on_error
    return func()
  File "/usr/lib/python3/dist-packages/univention/testing/utils.py", line 241, in __verify_ldap_object
    raise LDAPObjectNotFound('DN: %s' % baseDn)
univention.testing.utils.LDAPObjectNotFound: DN: cn=SSWV^}{$Ĵ´2,dc=autotest090,dc=local

Standard Ausgabe (STDOUT)

Creating container/cn object with /usr/sbin/udm-test container/cn create --set 'name=ßwv^}{$ĵ´2'
wait_for_drs_replication(): skip, univention-samba4 not installed.
Creating users/user object with /usr/sbin/udm-test users/user create --position 'cn=ßwv^}{$ĵ´2,dc=autotest090,dc=local' --set username=9e6m78uw6x --set password=univention --set lastname=yyjfr3s1rj --set firstname=h3ih77ujwl
Creating networks/network object with /usr/sbin/udm-test networks/network create --position 'cn=ßwv^}{$ĵ´2,dc=autotest090,dc=local' --set name=wvlfbiq9rd --set network=1.1.1.1 --set netmask=24
Modifying container/cn object with /usr/sbin/udm-test container/cn modify --dn 'cn=ßwv^}{$ĵ´2,dc=autotest090,dc=local' --set 'name=SSWV^}{$Ĵ´2'
Waiting for replication...
Done: replication complete.
Waiting for postrun...
. . . . . . . . . . . . . Postrun should have run
Exception occurred: <class 'univention.testing.utils.LDAPObjectNotFound'> (DN: cn=SSWV^}{$Ĵ´2,dc=autotest090,dc=local). Retrying in 10.00 seconds (retry 0/20).
Exception occurred: <class 'univention.testing.utils.LDAPObjectNotFound'> (DN: cn=SSWV^}{$Ĵ´2,dc=autotest090,dc=local). Retrying in 10.00 seconds (retry 1/20).
Exception occurred: <class 'univention.testing.utils.LDAPObjectNotFound'> (DN: cn=SSWV^}{$Ĵ´2,dc=autotest090,dc=local). Retrying in 10.00 seconds (retry 2/20).
Exception occurred: <class 'univention.testing.utils.LDAPObjectNotFound'> (DN: cn=SSWV^}{$Ĵ´2,dc=autotest090,dc=local). Retrying in 10.00 seconds (retry 3/20).
Exception occurred: <class 'univention.testing.utils.LDAPObjectNotFound'> (DN: cn=SSWV^}{$Ĵ´2,dc=autotest090,dc=local). Retrying in 10.00 seconds (retry 4/20).
Exception occurred: <class 'univention.testing.utils.LDAPObjectNotFound'> (DN: cn=SSWV^}{$Ĵ´2,dc=autotest090,dc=local). Retrying in 10.00 seconds (retry 5/20).
Exception occurred: <class 'univention.testing.utils.LDAPObjectNotFound'> (DN: cn=SSWV^}{$Ĵ´2,dc=autotest090,dc=local). Retrying in 10.00 seconds (retry 6/20).
Exception occurred: <class 'univention.testing.utils.LDAPObjectNotFound'> (DN: cn=SSWV^}{$Ĵ´2,dc=autotest090,dc=local). Retrying in 10.00 seconds (retry 7/20).
Exception occurred: <class 'univention.testing.utils.LDAPObjectNotFound'> (DN: cn=SSWV^}{$Ĵ´2,dc=autotest090,dc=local). Retrying in 10.00 seconds (retry 8/20).
Exception occurred: <class 'univention.testing.utils.LDAPObjectNotFound'> (DN: cn=SSWV^}{$Ĵ´2,dc=autotest090,dc=local). Retrying in 10.00 seconds (retry 9/20).
Exception occurred: <class 'univention.testing.utils.LDAPObjectNotFound'> (DN: cn=SSWV^}{$Ĵ´2,dc=autotest090,dc=local). Retrying in 10.00 seconds (retry 10/20).
Exception occurred: <class 'univention.testing.utils.LDAPObjectNotFound'> (DN: cn=SSWV^}{$Ĵ´2,dc=autotest090,dc=local). Retrying in 10.00 seconds (retry 11/20).
Exception occurred: <class 'univention.testing.utils.LDAPObjectNotFound'> (DN: cn=SSWV^}{$Ĵ´2,dc=autotest090,dc=local). Retrying in 10.00 seconds (retry 12/20).
Exception occurred: <class 'univention.testing.utils.LDAPObjectNotFound'> (DN: cn=SSWV^}{$Ĵ´2,dc=autotest090,dc=local). Retrying in 10.00 seconds (retry 13/20).
Exception occurred: <class 'univention.testing.utils.LDAPObjectNotFound'> (DN: cn=SSWV^}{$Ĵ´2,dc=autotest090,dc=local). Retrying in 10.00 seconds (retry 14/20).
Exception occurred: <class 'univention.testing.utils.LDAPObjectNotFound'> (DN: cn=SSWV^}{$Ĵ´2,dc=autotest090,dc=local). Retrying in 10.00 seconds (retry 15/20).
Exception occurred: <class 'univention.testing.utils.LDAPObjectNotFound'> (DN: cn=SSWV^}{$Ĵ´2,dc=autotest090,dc=local). Retrying in 10.00 seconds (retry 16/20).
Exception occurred: <class 'univention.testing.utils.LDAPObjectNotFound'> (DN: cn=SSWV^}{$Ĵ´2,dc=autotest090,dc=local). Retrying in 10.00 seconds (retry 17/20).
Exception occurred: <class 'univention.testing.utils.LDAPObjectNotFound'> (DN: cn=SSWV^}{$Ĵ´2,dc=autotest090,dc=local). Retrying in 10.00 seconds (retry 18/20).
Exception occurred: <class 'univention.testing.utils.LDAPObjectNotFound'> (DN: cn=SSWV^}{$Ĵ´2,dc=autotest090,dc=local). Retrying in 10.00 seconds (retry 19/20).
Exception occurred: <class 'univention.testing.utils.LDAPObjectNotFound'> (DN: cn=SSWV^}{$Ĵ´2,dc=autotest090,dc=local). This was the last retry (retry 20/20).
Performing UCSTestUDM cleanup...
removing DN: uid=9e6m78uw6x,cn=ßwv^}{$ĵ´2,dc=autotest090,dc=local
removing DN: cn=wvlfbiq9rd,cn=ßwv^}{$ĵ´2,dc=autotest090,dc=local
removing DN: cn=ßwv^}{$ĵ´2,dc=autotest090,dc=local
Cleanup: wait for replication and drs removal
OpenLDAP object to check against S4-Connector match_filter doesn't exist: uid=9e6m78uw6x,cn=ßwv^}{$ĵ´2,dc=autotest090,dc=local
DRS wait not required, S4-Connector match_filter did not match the OpenLDAP object: uid=9e6m78uw6x,cn=ßwv^}{$ĵ´2,dc=autotest090,dc=local
trying to restart UDM CLI server
sending signal 15 to process 5744 (['/usr/bin/python3', '/usr/share/univention-directory-manager-tools/univention-cli-server'])
process already terminated
UCSTestUDM cleanup done


https://jenkins.knut.univention.de:8181/job/UCS-5.0/job/UCS-5.0-0/job/AutotestJoin/lastCompletedBuild/SambaVersion=no-samba,Systemrolle=master/testReport/63_udm-containers.01_test_udm_containers/Test_ContainerCN/test_container_cn_rename_uppercase_rollback_with_special_characters/
Comment 1 Florian Best univentionstaff 2021-09-13 10:16:48 CEST
*** Bug 47724 has been marked as a duplicate of this bug. ***
Comment 2 Florian Best univentionstaff 2021-09-13 10:17:11 CEST
*** Bug 44853 has been marked as a duplicate of this bug. ***
Comment 3 Florian Best univentionstaff 2021-09-13 10:17:33 CEST
(In reply to Florian Best from comment #2)
> *** Bug 44853 has been marked as a duplicate of this bug. ***

(In reply to Dirk Wiesenthal from comment #1)
> Please add apptest tag again once this is fixed.
Comment 4 Florian Best univentionstaff 2021-09-13 10:25:06 CEST
01e73a497f57 | Bug #53776: [grep_traceback]: ignore traceback
Comment 5 Philipp Hahn univentionstaff 2021-09-14 21:25:53 CEST
Test failed twice for me today while testing Bug #53768 in my VM.
Is there some easy way to enable more debug output for this?
Comment 6 Philipp Hahn univentionstaff 2021-09-14 21:26:19 CEST
Created attachment 10824 [details]
Test output
Comment 7 Florian Best univentionstaff 2021-09-14 21:34:59 CEST
(In reply to Philipp Hahn from comment #5)
> Test failed twice for me today while testing Bug #53768 in my VM.
> Is there some easy way to enable more debug output for this?

Actually no, there are things going on inside UDM. I suspect we have a real error here:
* either S4-Connector removes / changes the container
* or there are only some characters which cause this error (the chars are randomly generated)

Maybe best would be to have a look at the translog or notifer transaction table.
Comment 8 Philipp Hahn univentionstaff 2021-09-15 10:43:11 CEST
One culprit is:
# python3 -c 'print("ß".upper())'
SS

 30                     cn_name = uts.random_name_special_characters()
 31                     cn_name_new = cn_name.upper()

(In reply to Florian Best from comment #7)
> (In reply to Philipp Hahn from comment #5)
> > Test failed twice for me today while testing Bug #53768 in my VM.
> > Is there some easy way to enable more debug output for this?
> 
> Actually no, there are things going on inside UDM. I suspect we have a real
> error here:
> * either S4-Connector removes / changes the container

No S4C in my case, so no one doing things in the background.

> * or there are only some characters which cause this error (the chars are
> randomly generated)

FAIL: cn=ŴSU!@SSŶ\,€Ẑ,dc=phahn,dc=dev
FAIL: cn=SSYV|}SS}\+ÛÄ,dc=phahn,dc=dev
FAIL: cn=SSHQ$(\"\<_ÂÜ,dc=phahn,dc=dev
FAIL: cn=ßhq$(\22\3C_âü,dc=phahn,dc=dev
OK: cn=ÊDGÛ-\\>%ÊĈ9,dc=phahn,dc=dev
OK: cn=ĈJQ]Ŷ(Ê {Ŝ,dc=phahn,dc=dev
OK: cn=ôby%?}Ω?&ẑ,dc=phahn,dc=dev
OK: cn=ŷwn€|:}!\+ĵ,dc=phahn,dc=dev
OK: cn=êyz\,ê-'"'"'ê(û,dc=phahn,dc=dev
OK: cn=ŵopĵ &½ĝ%â,dc=phahn,dc=dev

> Maybe best would be to have a look at the translog or notifer transaction
> table.

# ucr set listener/debug/level=3 notifier/debug/level=3 directory/manager/cmd/debug/level=3 tests/verify_ldap_object/retry_count=1
# systemctl restart univention-directory-{listener,notifier}
# cd /usr/share/ucs-test/63_udm-containers
# while pytest-3 -s 01_test_udm_containers.py::Test_ContainerCN::test_container_cn_rename_uppercase_rollback_with_special_characters;do :;done
(Pdb) p new_cn
'cn=SSRW!_\\<%?!4,dc=phahn,dc=dev'
    ^^
(Pdb) p new_user
'uid=g4zqps8ud1,cn=SSRW!_\\<%?!4,dc=phahn,dc=dev'

# udm container/cn list
…
DN: cn=ßrw!_\3C%?!4,dc=phahn,dc=dev
       ^

# univention-ldapsearch -LLLo ldif-wrap=no -b "$(ucr get ldap/base)" -s one -S createTimestamp '(cn=*)' createTimestamp modifyTimestamp | sed -re 's/^dn:: (.*)/echo \1|base64 -d/e'
…
cn=ßrw!_\3C%?!4,dc=phahn,dc=dev
   ^
createTimestamp: 20210915063140Z
modifyTimestamp: 20210915063140Z
Comment 9 Florian Best univentionstaff 2021-09-15 12:38:04 CEST
Thank you for the analysis. I did this once but didn't look close enough on the characters.
The problem/flakyness has increased since the Python 3 migration / UCS 5 because in Python 2 regular byte strings are returned:

>>> uts.random_name_special_characters()
"\xc4\x89ti'\xc2\xae\xe2\x82\xac\\#\xc4\x891"

I am not sure if this is the only problem of the test case, so let's wait a few weeks. I think from time to time I also see it failing in UCS 4.

ucs-test (10.0.6-45)
7624da348edf | Bug #53776: fix Test_ContainerCN::test_container_cn_rename_uppercase_rollback_with_special_characters with name containing "ß"