Bug 50338 - listener failed loading of modules during upgrade(?!)
listener failed loading of modules during upgrade(?!)
Status: NEW
Product: UCS
Classification: Unclassified
Component: Listener (univention-directory-listener)
UCS 4.4
Other Linux
: P5 normal (vote)
: ---
Assigned To: UCS maintainers
UCS maintainers
:
Depends on:
Blocks:
  Show dependency treegraph
 
Reported: 2019-10-10 12:45 CEST by Florian Best
Modified: 2020-08-10 09:48 CEST (History)
2 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
2019-10-10/AutotestUpgrade-s4connector-listener.log (1.72 MB, text/x-log)
2019-10-10 12:45 CEST, Florian Best
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Florian Best univentionstaff 2019-10-10 12:45:28 CEST
Created attachment 10201 [details]
2019-10-10/AutotestUpgrade-s4connector-listener.log

There are a lot of error happening during the upgrade when the listener (re)loads modules:

Today our daily jenkins tests contained the following tracebacks:

4 times:
Traceback (most recent call last):
  File "/usr/lib/univention-directory-listener/system/faillog.py", line 42, in <module>
    from univention.admin.handlers.users.user import unmapLocked
  File "/usr/lib/pymodules/python2.7/univention/admin/handlers/__init__.py", line 60, in <module>
    from univention.admindiary.client import write_event
 ImportError: No module named admindiary.client



2 times:
Traceback (most recent call last):
  File "/usr/lib/pymodules/python2.7/univention/admin/syntax.py", line 80, in import_syntax_files
    with open(fn, 'r') as fd:
 IOError: [Errno 2] No such file or directory: '/usr/lib/pymodules/python2.7/univention/admin/syntax.d/mailinglist_name.py'



15 times:
Traceback (most recent call last):
  File "/usr/lib/pymodules/python2.7/univention/listener/api_adapter.py", line 158, in _handler
    self._module_handler.error_handler(dn, old, new, command, exc_type, exc_value, exc_traceback)
  File "/usr/lib/pymodules/python2.7/univention/listener/api_adapter.py", line 155, in _handler
    self._module_handler.create(dn, new)
  File "/usr/lib/univention-directory-listener/system/app_attributes.py", line 194, in create
    self._write_json_without_some_debug_output()
  File "/usr/lib/univention-directory-listener/system/app_attributes.py", line 66, in _write_json_without_some_debug_output
    self._write_json()
  File "/usr/lib/univention-directory-listener/system/app_attributes.py", line 79, in _write_json
    app_objs = search_objects('appcenter/app', self.lo, self.po)
  File "/usr/lib/python2.7/dist-packages/univention/appcenter/udm.py", line 120, in search_objects
    module = _get_module(_module, _lo, _pos)
  File "/usr/lib/python2.7/dist-packages/univention/appcenter/udm.py", line 66, in _get_module
    _update_modules()
  File "/usr/lib/python2.7/dist-packages/univention/appcenter/udm.py", line 62, in _update_modules
    udm_modules.update()
  File "/usr/lib/pymodules/python2.7/univention/admin/modules.py", line 121, in update
    os.path.walk(dir, _walk, p)
  File "/usr/lib/python2.7/posixpath.py", line 239, in walk
    walk(name, func, arg)
  File "/usr/lib/python2.7/posixpath.py", line 231, in walk
    func(arg, top, names)
  File "/usr/lib/pymodules/python2.7/univention/admin/modules.py", line 106, in _walk
    m = __import__(mod, globals(), locals(), name)
  File "/usr/lib/pymodules/python2.7/univention/admin/handlers/computers/__init__.py", line 46, in <module>
    os.path.walk(path, __walk, path)
  File "/usr/lib/python2.7/posixpath.py", line 231, in walk
    func(arg, top, names)
  File "/usr/lib/pymodules/python2.7/univention/admin/handlers/computers/__init__.py", line 42, in __walk
    computers.append(__import__(file_[: -3], globals(), locals(), ['']))
  File "/usr/lib/pymodules/python2.7/univention/admin/handlers/computers/linux.py", line 38, in <module>
    from univention.admin.handlers.computers.__base import ComputerObject
 ImportError: No module named __base


15 times:
Traceback (most recent call last):
  File "/usr/lib/pymodules/python2.7/univention/listener/api_adapter.py", line 155, in _handler
    self._module_handler.create(dn, new)
  File "/usr/lib/univention-directory-listener/system/app_attributes.py", line 194, in create
    self._write_json_without_some_debug_output()
  File "/usr/lib/univention-directory-listener/system/app_attributes.py", line 66, in _write_json_without_some_debug_output
    self._write_json()
  File "/usr/lib/univention-directory-listener/system/app_attributes.py", line 79, in _write_json
    app_objs = search_objects('appcenter/app', self.lo, self.po)
  File "/usr/lib/python2.7/dist-packages/univention/appcenter/udm.py", line 120, in search_objects
    module = _get_module(_module, _lo, _pos)
  File "/usr/lib/python2.7/dist-packages/univention/appcenter/udm.py", line 66, in _get_module
    _update_modules()
  File "/usr/lib/python2.7/dist-packages/univention/appcenter/udm.py", line 62, in _update_modules
    udm_modules.update()
  File "/usr/lib/pymodules/python2.7/univention/admin/modules.py", line 121, in update
    os.path.walk(dir, _walk, p)
  File "/usr/lib/python2.7/posixpath.py", line 239, in walk
    walk(name, func, arg)
  File "/usr/lib/python2.7/posixpath.py", line 231, in walk
    func(arg, top, names)
  File "/usr/lib/pymodules/python2.7/univention/admin/modules.py", line 106, in _walk
    m = __import__(mod, globals(), locals(), name)
  File "/usr/lib/pymodules/python2.7/univention/admin/handlers/computers/__init__.py", line 46, in <module>
    os.path.walk(path, __walk, path)
  File "/usr/lib/python2.7/posixpath.py", line 231, in walk
    func(arg, top, names)
  File "/usr/lib/pymodules/python2.7/univention/admin/handlers/computers/__init__.py", line 42, in __walk
    computers.append(__import__(file_[: -3], globals(), locals(), ['']))
  File "/usr/lib/pymodules/python2.7/univention/admin/handlers/computers/linux.py", line 38, in <module>
    from univention.admin.handlers.computers.__base import ComputerObject
 ImportError: No module named __base


Attached is the full listener.log.
I hope this is fixed when we fully migrated to dh_python.
Comment 1 Florian Best univentionstaff 2019-10-17 10:24:00 CEST
Traceback (most recent call last):
  File "/usr/lib/univention-directory-listener/system/faillog.py", line 42, in <module>
    from univention.admin.handlers.users.user import unmapLocked
  File "/usr/lib/pymodules/python2.7/univention/admin/handlers/users/user.py", line 53, in <module>
    import univention.admin.handlers.groups.group
  File "/usr/lib/pymodules/python2.7/univention/admin/handlers/groups/group.py", line 1010, in <module>
    identify = object.identify
 AttributeError: type object 'object' has no attribute 'identify'
Comment 2 Florian Best univentionstaff 2019-12-20 08:23:00 CET
2019-12-20/AutotestUpgrade-s4-listener.log:
Traceback (most recent call last):
  File "/usr/lib/pymodules/python2.7/univention/listener/api_adapter.py", line 158, in _handler
  File "/usr/lib/pymodules/python2.7/univention/listener/api_adapter.py", line 150, in _handler
  File "/usr/lib/univention-directory-listener/system/app_attributes.py", line 198, in modify
    self._write_json_without_some_debug_output()
  File "/usr/lib/univention-directory-listener/system/app_attributes.py", line 66, in _write_json_without_some_debug_output
    self._write_json()
  File "/usr/lib/univention-directory-listener/system/app_attributes.py", line 79, in _write_json
    app_objs = search_objects('appcenter/app', self.lo, self.po)
  File "/usr/lib/python2.7/dist-packages/univention/appcenter/udm.py", line 120, in search_objects
    module = _get_module(_module, _lo, _pos)
  File "/usr/lib/python2.7/dist-packages/univention/appcenter/udm.py", line 66, in _get_module
    _update_modules()
  File "/usr/lib/python2.7/dist-packages/univention/appcenter/udm.py", line 62, in _update_modules
    udm_modules.update()
  File "/usr/lib/pymodules/python2.7/univention/admin/modules.py", line 123, in update
  File "/usr/lib/python2.7/posixpath.py", line 239, in walk 
    walk(name, func, arg) 
  File "/usr/lib/python2.7/posixpath.py", line 231, in walk 
    func(arg, top, names)
  File "/usr/lib/pymodules/python2.7/univention/admin/modules.py", line 108, in _walk
 ImportError: No module named directory
Comment 3 Florian Best univentionstaff 2019-12-20 08:28:51 CET
We have a lot of these tracebacks in modify(), create(), remove()…:

Traceback (most recent call last):
  File "/usr/lib/python2.7/dist-packages/univention/admin/syntax.py", line 91, in import_syntax_files
    with open(fn, 'r') as fd:
 IOError: [Errno 2] No such file or directory: '/usr/lib/pymodules/python2.7/univention/admin/syntax.d/univention-virtual-machine-manager-schema.py'

Traceback (most recent call last):
  File "/usr/lib/pymodules/python2.7/univention/admin/syntax.py", line 80, in import_syntax_files
    with open(fn, 'r') as fd:
 IOError: [Errno 2] No such file or directory: '/usr/lib/pymodules/python2.7/univention/admin/syntax.d/mailinglist_name.py'

Traceback (most recent call last):
  File "/usr/lib/univention-directory-listener/system/quota.py", line 217, in handler
    _add_all_shares_below_this_container_to_dn_list(dn)
  File "/usr/lib/univention-directory-listener/system/quota.py", line 173, in _add_all_shares_below_this_container_to_dn_list
    for dn, attr in lo.search(base=container_dn, filter='(&(objectClass=univentionShare)(univentionShareHost=%s))' % _get_fqdn(), attr=['dn']):
  File "/usr/lib/python2.7/dist-packages/univention/uldap.py", line 199, in _decorated
    return func(self, *args, **kwargs)
  File "/usr/lib/python2.7/dist-packages/univention/uldap.py", line 507, in search
    res = self.lo.search_ext_s(base, ldap_scope, filter, attr, serverctrls=serverctrls, clientctrls=None, timeout=timeout, sizelimit=sizelimit)
  File "/usr/lib/python2.7/dist-packages/ldap/ldapobject.py", line 993, in search_ext_s
    return self._apply_method_s(SimpleLDAPObject.search_ext_s,*args,**kwargs)
  File "/usr/lib/python2.7/dist-packages/ldap/ldapobject.py", line 931, in _apply_method_s
    return func(self,*args,**kwargs)
  File "/usr/lib/python2.7/dist-packages/ldap/ldapobject.py", line 591, in search_ext_s
    return self.result(msgid,all=1,timeout=timeout)[1]
  File "/usr/lib/python2.7/dist-packages/ldap/ldapobject.py", line 503, in result
    resp_type, resp_data, resp_msgid = self.result2(msgid,all,timeout)
  File "/usr/lib/python2.7/dist-packages/ldap/ldapobject.py", line 507, in result2
    resp_type, resp_data, resp_msgid, resp_ctrls = self.result3(msgid,all,timeout)
  File "/usr/lib/python2.7/dist-packages/ldap/ldapobject.py", line 514, in result3
    resp_ctrl_classes=resp_ctrl_classes
  File "/usr/lib/python2.7/dist-packages/ldap/ldapobject.py", line 521, in result4
    ldap_result = self._ldap_call(self._l.result4,msgid,all,timeout,add_ctrls,add_intermediates,add_extop)
  File "/usr/lib/python2.7/dist-packages/ldap/ldapobject.py", line 106, in _ldap_call
    result = func(*args,**kwargs)
 ldap.NO_SUCH_OBJECT: {'matched': 'dc=AutoTest071,dc=local', 'desc': 'No such object'}
→ this is maybe worth an extra bug.
Comment 4 Arvid Requate univentionstaff 2019-12-20 15:02:38 CET
Can you give an estimate of the effect of this?
Do you think it will have severe consequences, like causing listener module malfunction during replication?
Comment 5 Florian Best univentionstaff 2019-12-20 15:08:07 CET
(In reply to Arvid Requate from comment #4)
> Can you give an estimate of the effect of this?
> Do you think it will have severe consequences, like causing listener module
> malfunction during replication?

I think we loose the listener-module effect for some transactions:
* The listener doesn't retry executing listener module if any exception occurred in it.

Maybe this is the real cause for the problems in the Portal, that didn't evaluate the correct permissions (I don't find the bug number currently).

And it's potentially bad for things we develop in the future.
I created this bug, so that we analyze why and when this happens (probably during package upgrade with multiple errata updates in a stage between preinst, unpacking, postinst of some packages).
And I want that we find a solution so that this cannot occur anymore.
About the tracebacks from the history I don't care; We can't change this either anymore.