Univention Bugzilla – Bug 49723
10_ldap.41listener_module_api_test fails on samba master
Last modified: 2019-06-24 15:55:16 CEST
... (2019-06-24 01:17:17.296127) *** Deleting user... [2019-06-24 01:17:17.305009] Unsetting listener/module/test-mbggon5kog/debug/level [2019-06-24 01:17:17.446111] Performing UCSTestUDM cleanup... [2019-06-24 01:17:17.446180] removing DN: uid=msnf8yhgsi,cn=users,dc=AutoTest091,dc=local [2019-06-24 01:17:17.600122] Cleanup: wait for replication and drs removal [2019-06-24 01:17:18.667676] OpenLDAP object to check against S4-Connector match_filter doesn't exist: uid=msnf8yhgsi,cn=users,dc=AutoTest091,dc=local [2019-06-24 01:17:18.667728] DRS wait not required, S4-Connector match_filter did not match the OpenLDAP object: uid=msnf8yhgsi,cn=users,dc=AutoTest091,dc=local [2019-06-24 01:17:18.667753] trying to restart UDM CLI server [2019-06-24 01:17:18.690706] sending signal 15 to process 3867 (['/usr/bin/python2.7', '/usr/share/univention-directory-manager-tools/univention-cli-server']) [2019-06-24 01:17:19.691997] process already terminated [2019-06-24 01:17:19.692049] UCSTestUDM cleanup done [2019-06-24 01:17:19.801489] Waiting for DRS replication, filter: '(!(cn=msnf8yhgsi))', base: 'DC=autotest091,DC=local', scope: 2, should_exist: True [2019-06-24 01:17:19.801539] DRS replication took 0 seconds [2019-06-24 01:17:20.908305] OK: replication complete (nid=4581 lid=4581) [2019-06-24 01:17:21.293158] highestCommittedUSN: 4237 [2019-06-24 01:17:21.293205] lastUSN: 4237 [2019-06-24 01:17:21.293253] Reset counter [2019-06-24 01:17:21.293267] Counter: 0 [2019-06-24 01:17:22.359068] OK: replication complete (nid=4581 lid=4581) [2019-06-24 01:17:22.734659] highestCommittedUSN: 4237 [2019-06-24 01:17:22.734706] lastUSN: 4237 [2019-06-24 01:17:22.734754] Counter: 1 [2019-06-24 01:17:23.799898] OK: replication complete (nid=4581 lid=4581) [2019-06-24 01:17:24.170223] highestCommittedUSN: 4237 [2019-06-24 01:17:24.170267] lastUSN: 4237 [2019-06-24 01:17:24.170315] Counter: 2 [2019-06-24 01:17:25.235607] OK: replication complete (nid=4581 lid=4581) [2019-06-24 01:17:25.598882] highestCommittedUSN: 4237 [2019-06-24 01:17:25.598926] lastUSN: 4237 [2019-06-24 01:17:25.598973] Counter: 3 [2019-06-24 01:17:26.663491] OK: replication complete (nid=4581 lid=4581) [2019-06-24 01:17:27.036570] highestCommittedUSN: 4237 [2019-06-24 01:17:27.036614] lastUSN: 4237 [2019-06-24 01:17:27.036660] Counter: 4 [2019-06-24 01:17:28.102056] OK: replication complete (nid=4581 lid=4581) [2019-06-24 01:17:28.470281] highestCommittedUSN: 4237 [2019-06-24 01:17:28.470325] lastUSN: 4237 [2019-06-24 01:17:28.470372] Counter: 5 [2019-06-24 01:17:29.535728] OK: replication complete (nid=4581 lid=4581) [2019-06-24 01:17:29.908192] highestCommittedUSN: 4237 [2019-06-24 01:17:29.908237] lastUSN: 4237 [2019-06-24 01:17:29.908283] Counter: 6 [2019-06-24 01:17:30.972403] OK: replication complete (nid=4581 lid=4581) [2019-06-24 01:17:31.353186] highestCommittedUSN: 4237 [2019-06-24 01:17:31.353234] lastUSN: 4237 [2019-06-24 01:17:31.353279] Counter: 7 [2019-06-24 01:17:32.419189] OK: replication complete (nid=4581 lid=4581) [2019-06-24 01:17:32.795932] highestCommittedUSN: 4237 [2019-06-24 01:17:32.795977] lastUSN: 4237 [2019-06-24 01:17:32.796024] Counter: 8 [2019-06-24 01:17:33.861024] OK: replication complete (nid=4581 lid=4581) [2019-06-24 01:17:34.230269] highestCommittedUSN: 4237 [2019-06-24 01:17:34.230313] lastUSN: 4237 [2019-06-24 01:17:34.230360] Counter: 9 [2019-06-24 01:17:35.294961] OK: replication complete (nid=4581 lid=4581) [2019-06-24 01:17:35.670332] highestCommittedUSN: 4237 [2019-06-24 01:17:35.670381] lastUSN: 4237 [2019-06-24 01:17:35.670441] Counter: 10 [2019-06-24 01:17:35.670853] ** Entering verify_ldap_object [2019-06-24 01:17:35.687280] ** Exiting verify_ldap_object [2019-06-24 01:17:50.702602] ******************************************* [2019-06-24 01:17:50.702658] /var/log/univention/listener_modules/test-mbggon5kog.log [2019-06-24 01:17:50.702681] ---------- [2019-06-24 01:17:50.702747] 2019-06-24 01:16:24 INFO *** Creating user... [2019-06-24 01:17:50.702786] 2019-06-24 01:16:26 DEBUG handler.__init__:104 Starting with configuration: ListenerModuleConfiguration(attributes=['employeeType', 'roomNumber'], listener_module_class=<class '/usr/lib/univention-directory-listener/system/test-mbggon5kog.py.TestListenerModule'>, description='test module #y7s72fedol', name='test-mbggon5kog', ldap_filter='(&(objectClass=inetOrgPerson)(uid=msnf8yhgsi))') [2019-06-24 01:17:50.702816] 2019-06-24 01:16:26 INFO test-mbggon5kog.create:37 create() for user 'msnf8yhgsi'. [2019-06-24 01:17:50.702840] 2019-06-24 01:16:26 INFO test-mbggon5kog.create:38 create() touch uid root '/tmp/fgr8kkyf2x'. [2019-06-24 01:17:50.702866] 2019-06-24 01:16:26 INFO test-mbggon5kog.create:41 create() touch uid listener '/tmp/q4u39ulqvb.log'. [2019-06-24 01:17:50.702892] 2019-06-24 01:16:26 INFO test-mbggon5kog.create:43 create() test self.lo [2019-06-24 01:17:50.702914] 2019-06-24 01:16:26 DEBUG test-mbggon5kog.create:45 filter_s='(&(objectClass=posixAccount)(uid=msnf8yhgsi))' [2019-06-24 01:17:50.703012] 2019-06-24 01:16:26 DEBUG test-mbggon5kog.create:47 ldap_res=['uid=msnf8yhgsi,cn=users,dc=AutoTest091,dc=local'] [2019-06-24 01:17:50.703039] 2019-06-24 01:16:46 INFO *** Checking setuid()... [2019-06-24 01:17:50.703062] 2019-06-24 01:16:46 INFO *** Modifying user (employeeType)... [2019-06-24 01:17:50.703087] 2019-06-24 01:16:47 INFO test-mbggon5kog.modify:63 modify() for user 'msnf8yhgsi'. diff(old, new)={'employeeType': (None, ['w609vk3dij'])} [2019-06-24 01:17:50.703116] 2019-06-24 01:16:51 INFO *** Moving user (to LDAP base)... [2019-06-24 01:17:50.703143] 2019-06-24 01:16:52 INFO test-mbggon5kog.modify:59 modify() MOVE for user 'msnf8yhgsi'. old_dn='uid=msnf8yhgsi,cn=users,dc=AutoTest091,dc=local' | new dn='uid=msnf8yhgsi,dc=AutoTest091,dc=local' | diff(old, new)={} [2019-06-24 01:17:50.703167] 2019-06-24 01:16:53 INFO *** Modifying user (street) should not trigger listener module... [2019-06-24 01:17:50.703188] 2019-06-24 01:16:54 INFO *** Moving user (to cn=users)... [2019-06-24 01:17:50.703218] 2019-06-24 01:16:54 INFO test-mbggon5kog.modify:59 modify() MOVE for user 'msnf8yhgsi'. old_dn='uid=msnf8yhgsi,dc=AutoTest091,dc=local' | new dn='uid=msnf8yhgsi,cn=users,dc=AutoTest091,dc=local' | diff(old, new)={} [2019-06-24 01:17:50.703240] 2019-06-24 01:16:55 INFO *** Modifying user (roomNumber) and triggering error... [2019-06-24 01:17:50.703289] 2019-06-24 01:16:55 INFO test-mbggon5kog.modify:63 modify() for user 'msnf8yhgsi'. diff(old, new)={'roomNumber': (None, ['os82zfl35c'])} [2019-06-24 01:17:50.703310] 2019-06-24 01:17:00 ERROR test-mbggon5kog.error_handler:82 Traceback (most recent call last): [2019-06-24 01:17:50.703327] File "/usr/lib/pymodules/python2.7/univention/listener/api_adapter.py", line 150, in _handler [2019-06-24 01:17:50.703344] self._module_handler.modify(dn, old, new, self._saved_old_dn if self._rename else None) [2019-06-24 01:17:50.703360] File "/usr/lib/univention-directory-listener/system/test-mbggon5kog.py", line 69, in modify [2019-06-24 01:17:50.703376] raise MyTestException('Error {}.'.format(TEST_ID)) [2019-06-24 01:17:50.703395] MyTestException: Error y7s72fedol. [2019-06-24 01:17:50.703410] 2019-06-24 01:17:17 INFO *** Deleting user... [2019-06-24 01:17:50.703427] 2019-06-24 01:17:17 INFO test-mbggon5kog.remove:74 remove() for user 'msnf8yhgsi'. [2019-06-24 01:17:50.703442] ******************************************* [2019-06-24 01:17:50.703456] ******************************************* [2019-06-24 01:17:50.703470] /tmp/pi8fxi5e7b.log [2019-06-24 01:17:50.703485] ---------- [2019-06-24 01:17:50.703499] y7s72fedol clean [2019-06-24 01:17:50.703512] y7s72fedol initialize [2019-06-24 01:17:50.703527] y7s72fedol pre_run [2019-06-24 01:17:50.703543] y7s72fedol create msnf8yhgsi [2019-06-24 01:17:50.703557] y7s72fedol post_run [2019-06-24 01:17:50.703572] y7s72fedol pre_run [2019-06-24 01:17:50.703613] y7s72fedol modify employeeType w609vk3dij msnf8yhgsi [2019-06-24 01:17:50.703633] y7s72fedol move msnf8yhgsi [2019-06-24 01:17:50.703648] y7s72fedol move msnf8yhgsi [2019-06-24 01:17:50.703664] y7s72fedol modify roomNumber os82zfl35c msnf8yhgsi [2019-06-24 01:17:50.703680] y7s72fedol error_handler msnf8yhgsi [2019-06-24 01:17:50.703695] y7s72fedol post_run [2019-06-24 01:17:50.703711] y7s72fedol pre_run [2019-06-24 01:17:50.703726] y7s72fedol remove msnf8yhgsi [2019-06-24 01:17:50.703742] y7s72fedol post_run [2019-06-24 01:17:50.703759] ******************************************* [2019-06-24 01:17:50.703775] ### FAIL ### [2019-06-24 01:17:50.703795] Expected startswith('y7s72fedol modify employeeType w609vk3dij') found 'y7s72fedol post_run'. [2019-06-24 01:17:50.703813] ### ### [2019-06-24 01:17:50.703832] Deleting '/usr/lib/univention-directory-listener/system/test-mbggon5kog.py'... [2019-06-24 01:17:50.703849] Deleting '/tmp/pi8fxi5e7b.log'... [2019-06-24 01:17:50.703866] Deleting '/tmp/q4u39ulqvb.log'... [2019-06-24 01:17:50.703884] Deleting '/tmp/fgr8kkyf2x'... [2019-06-24 01:17:50.703902] Restarting univention-directory-listener...
disabled for systems witch univention-samba4 ucs-test - d6bf9be935f84a58f2e847df08286e882b4767d2