Univention Bugzilla – Bug 45676
UMC-Server crashes with "KeyError: appcenter"
Last modified: 2017-11-15 17:13:09 CET
The current jenkins selenium tests revealed a UMC-Server crash: 08.11.17 23:51:42.789 MAIN ( PROCESS ) : Connection timed out. 08.11.17 23:51:42.789 MAIN ( PROCESS ) : Processor: dying 08.11.17 23:51:42.789 MAIN ( PROCESS ) : Processor: dying 08.11.17 23:51:43.094 MAIN ( PROCESS ) : running: ['/usr/sbin/univention-management-console-module', '-m', 'join', '-s', '/var/run/univention-management-console/4059-1510203103094.socket', '-d', '2', '-l', 'en_US.UTF-8'] 08.11.17 23:51:43.143 MAIN ( PROCESS ) : running: ['/usr/sbin/univention-management-console-module', '-m', 'appcenter', '-s', '/var/run/univention-management-console/4059-1510203103143.socket', '-d', '2', '-l', 'en_US.UTF-8'] 08.11.17 23:51:43.216 MAIN ( PROCESS ) : running: ['/usr/sbin/univention-management-console-module', '-m', 'updater', '-s', '/var/run/univention-management-console/4059-1510203103215.socket', '-d', '2', '-l', 'en_US.UTF-8'] 08.11.17 23:51:43.830 MAIN ( PROCESS ) : Connection timed out. 08.11.17 23:51:46.039 MAIN ( WARN ) : Socket died (module=join) 08.11.17 23:51:46.039 MAIN ( WARN ) : Module process join died (pid: 4218, exit status: -1, signal: -1, status: -1) 08.11.17 23:51:46.039 MAIN ( WARN ) : Cleaning up requests 08.11.17 23:51:46.039 MAIN ( WARN ) : Remove inactivity timer 08.11.17 23:51:46.051 MAIN ( PROCESS ) : ModuleProcess: child died 08.11.17 23:51:46.051 MAIN ( WARN ) : Module process join died (pid: 4218, exit status: -1, signal: 9, status: 9) 08.11.17 23:51:46.054 MAIN ( WARN ) : Socket died (module=join) 08.11.17 23:51:46.054 MAIN ( WARN ) : Module process join died (pid: 4681, exit status: -1, signal: -1, status: -1) 08.11.17 23:51:46.054 MAIN ( WARN ) : Cleaning up requests 08.11.17 23:51:46.054 MAIN ( WARN ) : Remove inactivity timer 08.11.17 23:51:46.070 MAIN ( WARN ) : Socket died (module=updater) 08.11.17 23:51:46.070 MAIN ( WARN ) : Module process updater died (pid: 4683, exit status: -1, signal: -1, status: -1) 08.11.17 23:51:46.070 MAIN ( WARN ) : Cleaning up requests 08.11.17 23:51:46.070 MAIN ( WARN ) : Remove inactivity timer 08.11.17 23:51:46.070 MAIN ( PROCESS ) : ModuleProcess: child died 08.11.17 23:51:46.070 MAIN ( WARN ) : Module process join died (pid: 4681, exit status: -1, signal: 9, status: 9) 08.11.17 23:51:46.074 MAIN ( WARN ) : Socket died (module=ucr) 08.11.17 23:51:46.074 MAIN ( WARN ) : Module process ucr died (pid: 4921, exit status: -1, signal: -1, status: -1) 08.11.17 23:51:46.074 MAIN ( WARN ) : Cleaning up requests 08.11.17 23:51:46.074 MAIN ( WARN ) : Remove inactivity timer 08.11.17 23:51:46.074 MAIN ( PROCESS ) : ModuleProcess: child died 08.11.17 23:51:46.074 MAIN ( WARN ) : Module process updater died (pid: 4683, exit status: -1, signal: 9, status: 9) 08.11.17 23:51:46.078 MAIN ( WARN ) : Socket died (module=join) 08.11.17 23:51:46.078 MAIN ( WARN ) : Module process join died (pid: 5128, exit status: -1, signal: -1, status: -1) 08.11.17 23:51:46.078 MAIN ( WARN ) : Cleaning up requests 08.11.17 23:51:46.078 MAIN ( WARN ) : Remove inactivity timer 08.11.17 23:51:46.078 MAIN ( PROCESS ) : ModuleProcess: child died 08.11.17 23:51:46.078 MAIN ( WARN ) : Module process ucr died (pid: 4921, exit status: -1, signal: 9, status: 9) 08.11.17 23:51:46.091 MAIN ( PROCESS ) : ModuleProcess: child died 08.11.17 23:51:46.091 MAIN ( WARN ) : Module process join died (pid: 5128, exit status: -1, signal: 9, status: 9) 08.11.17 23:51:46.095 MAIN ( WARN ) : Socket died (module=appcenter) 08.11.17 23:51:46.095 MAIN ( WARN ) : Module process appcenter died (pid: 5129, exit status: -1, signal: -1, status: -1) 08.11.17 23:51:46.095 MAIN ( WARN ) : Cleaning up requests 08.11.17 23:51:46.095 MAIN ( WARN ) : Remove inactivity timer 08.11.17 23:51:46.099 MAIN ( PROCESS ) : ModuleProcess: child died 08.11.17 23:51:46.099 MAIN ( WARN ) : Module process appcenter died (pid: 5129, exit status: -1, signal: 9, status: 9) 08.11.17 23:51:46.099 MAIN ( WARN ) : Socket died (module=updater) 08.11.17 23:51:46.099 MAIN ( WARN ) : Module process updater died (pid: 5130, exit status: -1, signal: -1, status: -1) 08.11.17 23:51:46.099 MAIN ( WARN ) : Cleaning up requests 08.11.17 23:51:46.099 MAIN ( WARN ) : Remove inactivity timer 08.11.17 23:51:46.110 MAIN ( WARN ) : Socket died (module=join) 08.11.17 23:51:46.110 MAIN ( WARN ) : Module process join died (pid: 5261, exit status: -1, signal: -1, status: -1) 08.11.17 23:51:46.110 MAIN ( WARN ) : Cleaning up requests 08.11.17 23:51:46.110 MAIN ( WARN ) : Remove inactivity timer 08.11.17 23:51:46.114 MAIN ( WARN ) : Socket died (module=updater) 08.11.17 23:51:46.114 MAIN ( WARN ) : Module process updater died (pid: 5263, exit status: -1, signal: -1, status: -1) 08.11.17 23:51:46.114 MAIN ( WARN ) : Cleaning up requests 08.11.17 23:51:46.114 MAIN ( WARN ) : Remove inactivity timer 08.11.17 23:51:46.114 MAIN ( PROCESS ) : ModuleProcess: child died 08.11.17 23:51:46.114 MAIN ( WARN ) : Module process join died (pid: 5261, exit status: -1, signal: 9, status: 9) 08.11.17 23:51:46.130 MAIN ( WARN ) : Socket died (module=updater) 08.11.17 23:51:46.130 MAIN ( WARN ) : Module process updater died (pid: 5406, exit status: -1, signal: -1, status: -1) 08.11.17 23:51:46.130 MAIN ( WARN ) : Cleaning up requests 08.11.17 23:51:46.130 MAIN ( WARN ) : Remove inactivity timer 08.11.17 23:51:46.130 MAIN ( PROCESS ) : ModuleProcess: child died 08.11.17 23:51:46.130 MAIN ( WARN ) : Module process updater died (pid: 5263, exit status: -1, signal: 9, status: 9) 08.11.17 23:51:46.131 MAIN ( WARN ) : Socket died (module=join) 08.11.17 23:51:46.131 MAIN ( WARN ) : Module process join died (pid: 5404, exit status: -1, signal: -1, status: -1) 08.11.17 23:51:46.131 MAIN ( WARN ) : Cleaning up requests 08.11.17 23:51:46.131 MAIN ( WARN ) : Remove inactivity timer 08.11.17 23:51:46.131 MAIN ( PROCESS ) : ModuleProcess: child died 08.11.17 23:51:46.131 MAIN ( WARN ) : Module process updater died (pid: 5406, exit status: -1, signal: 9, status: 9) 08.11.17 23:51:46.148 MAIN ( PROCESS ) : ModuleProcess: child died 08.11.17 23:51:46.148 MAIN ( WARN ) : Module process join died (pid: 5404, exit status: -1, signal: 9, status: 9) 08.11.17 23:51:46.152 MAIN ( WARN ) : Socket died (module=appcenter) 08.11.17 23:51:46.152 MAIN ( WARN ) : Module process appcenter died (pid: 4682, exit status: -1, signal: -1, status: -1) 08.11.17 23:51:46.152 MAIN ( WARN ) : Cleaning up requests 08.11.17 23:51:46.152 MAIN ( WARN ) : Remove inactivity timer 08.11.17 23:51:46.152 MAIN ( WARN ) : Socket died (module=updater) 08.11.17 23:51:46.152 MAIN ( WARN ) : Module process updater died (pid: 4219, exit status: -1, signal: -1, status: -1) 08.11.17 23:51:46.152 MAIN ( WARN ) : Cleaning up requests 08.11.17 23:51:46.152 MAIN ( WARN ) : Remove inactivity timer 08.11.17 23:51:46.188 MAIN ( PROCESS ) : ModuleProcess: child died 08.11.17 23:51:46.188 MAIN ( WARN ) : Module process updater died (pid: 4219, exit status: -1, signal: 9, status: 9) 08.11.17 23:51:46.188 MAIN ( PROCESS ) : ModuleProcess: child died 08.11.17 23:51:46.188 MAIN ( WARN ) : Module process appcenter died (pid: 4682, exit status: -1, signal: 9, status: 9) 08.11.17 23:51:46.188 MAIN ( PROCESS ) : ModuleProcess: child died 08.11.17 23:51:46.189 MAIN ( WARN ) : Module process updater died (pid: 5130, exit status: -1, signal: 9, status: 9) 08.11.17 23:51:46.189 MAIN ( PROCESS ) : ModuleProcess: child died 08.11.17 23:51:46.189 MAIN ( WARN ) : Module process join died (pid: 5533, exit status: -1, signal: 9, status: 9) 08.11.17 23:51:46.189 MAIN ( WARN ) : Cleaning up requests 08.11.17 23:51:46.189 MAIN ( PROCESS ) : ModuleProcess: child died 08.11.17 23:51:46.189 MAIN ( WARN ) : Module process updater died (pid: 5535, exit status: -1, signal: 9, status: 9) 08.11.17 23:51:46.189 MAIN ( WARN ) : Cleaning up requests 08.11.17 23:51:46.205 MAIN ( PROCESS ) : ModuleProcess: child died 08.11.17 23:51:46.205 MAIN ( WARN ) : Module process appcenter died (pid: 5534, exit status: -1, signal: 9, status: 9) 08.11.17 23:51:46.205 MAIN ( WARN ) : Cleaning up requests 08.11.17 23:51:46.221 MAIN ( PROCESS ) : Connection timed out. 08.11.17 23:51:46.796 MAIN ( PROCESS ) : Connection timed out. 08.11.17 23:51:46.796 MAIN ( PROCESS ) : Processor: dying 08.11.17 23:51:46.796 MAIN ( PROCESS ) : Connection timed out. 08.11.17 23:51:46.796 MAIN ( PROCESS ) : Processor: dying 08.11.17 23:51:50.002 MAIN ( PROCESS ) : running: ['/usr/sbin/univention-management-console-module', '-m', 'join', '-s', '/var/run/univention-management-console/4059-1510203110002.socket', '-d', '2', '-l', 'en_US.UTF-8'] 08.11.17 23:51:50.120 MAIN ( PROCESS ) : running: ['/usr/sbin/univention-management-console-module', '-m', 'appcenter', '-s', '/var/run/univention-management-console/4059-1510203110120.socket', '-d', '2', '-l', 'en_US.UTF-8'] 08.11.17 23:51:50.169 MAIN ( PROCESS ) : running: ['/usr/sbin/univention-management-console-module', '-m', 'updater', '-s', '/var/run/univention-management-console/4059-1510203110169.socket', '-d', '2', '-l', 'en_US.UTF-8'] 08.11.17 23:51:53.349 MAIN ( PROCESS ) : ModuleProcess: dying 08.11.17 23:51:53.349 MAIN ( WARN ) : Socket died (module=appcenter) 08.11.17 23:51:53.349 MAIN ( WARN ) : Module process appcenter died (pid: 5548, exit status: -1, signal: -1, status: -1) 08.11.17 23:51:53.349 MAIN ( WARN ) : Cleaning up requests 08.11.17 23:51:53.349 MAIN ( PROCESS ) : ModuleProcess: child stopped 08.11.17 23:51:53.377 MAIN ( ERROR ) : Traceback (most recent call last): File "/usr/sbin/univention-management-console-server", line 243, in <module> umc_daemon.do_action() File "/usr/lib/pymodules/python2.7/daemon/runner.py", line 186, in do_action func(self) File "/usr/lib/pymodules/python2.7/daemon/runner.py", line 131, in _start self.app.run() File "/usr/sbin/univention-management-console-server", line 210, in run notifier.loop() File "/usr/lib/pymodules/python2.7/notifier/nf_generic.py", line 286, in loop step() File "/usr/lib/pymodules/python2.7/notifier/nf_generic.py", line 242, in step if not timer[ CALLBACK ](): File "/usr/lib/pymodules/python2.7/notifier/__init__.py", line 104, in __call__ return self._function( *tmp, **self._kwargs ) File "/usr/lib/pymodules/python2.7/univention/management/console/protocol/session.py", line 544, in _mod_connect _send_error() File "/usr/lib/pymodules/python2.7/univention/management/console/protocol/session.py", line 537, in _send_error del self.__processes[mod.name] KeyError: 'appcenter' The appcenter log contains only: 08.11.17 23:50:39.944 DEBUG_INIT 08.11.17 23:50:46.773 MODULE ( PROCESS ) : Loading python module. 08.11.17 23:50:47.788 MODULE ( PROCESS ) : Imported python module. 08.11.17 23:50:47.788 MODULE ( PROCESS ) : Module instance created. 08.11.17 23:50:47.789 MODULE ( PROCESS ) : Module socket initialized. 08.11.17 23:50:47.801 MODULE ( PROCESS ) : Setting user LDAP DN 'uid=Administrator,cn=users,dc=autotest095,dc=local' 08.11.17 23:50:47.801 MODULE ( PROCESS ) : Setting auth type to None 08.11.17 23:50:47.801 MODULE ( PROCESS ) : Initializing module. 08.11.17 23:51:02.192 DEBUG_INIT 08.11.17 23:51:10.230 MODULE ( PROCESS ) : Loading python module. 08.11.17 23:51:24.992 DEBUG_INIT 08.11.17 23:51:33.155 MODULE ( PROCESS ) : Loading python module. 08.11.17 23:51:44.743 DEBUG_INIT 08.11.17 23:51:51.752 DEBUG_INIT 08.11.17 23:51:57.543 MODULE ( PROCESS ) : Loading python module. 08.11.17 23:51:58.361 MODULE ( PROCESS ) : Imported python module. 08.11.17 23:51:58.371 MODULE ( PROCESS ) : Module instance created. 08.11.17 23:51:58.372 MODULE ( PROCESS ) : Module socket initialized. 08.11.17 23:52:26.594 MAIN ( WARN ) : Shutting down all open connections
The code block is the following: 535 » » » if mod.name in self.__processes: 536 » » » » self.__processes[mod.name].__del__() 537 » » » » del self.__processes[mod.name] → So it must be a concurrency / threading issue.
The code is during handling an error if the connection to a module process can't be established in 10 seconds. This only happens during high load. univention-management-console.yaml 51876d73f902 | Bug #45676: Merge branch 'fbest/45676-umc-server-crash-theading' into 4.2-2 2ae5b572ec2b | YAML Bug #45676 univention-management-console (9.0.80-80) 51876d73f902 | Bug #45676: Merge branch 'fbest/45676-umc-server-crash-theading' into 4.2-2 616037600da4 | Bug #45676: fix a UMC-Server crash caused by a threading issue during
This seems working and caused no other crash in another thread.
The problem is gone and the code looks reasonable. -> Verified
<http://errata.software-univention.de/ucs/4.2/221.html>