Bug 44365 - UMC server crashes IndexError: tuple index out of range
UMC server crashes IndexError: tuple index out of range
Status: CLOSED FIXED
Product: UCS
Classification: Unclassified
Component: UMC (Generic)
UCS 4.2
Other Linux
: P5 critical (vote)
: UCS 4.2-0-errata
Assigned To: Florian Best
Felix Botner
:
Depends on:
Blocks: 44647
  Show dependency treegraph
 
Reported: 2017-04-13 10:53 CEST by Felix Botner
Modified: 2017-06-15 17:58 CEST (History)
1 user (show)

See Also:
What kind of report is it?: Bug Report
What type of bug is this?: 7: Crash: Bug causes crash or data loss
Who will be affected by this bug?: 2: Will only affect a few installed domains
How will those affected feel about the bug?: 3: A User would likely not purchase the product
User Pain: 0.240
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
management-console-module-adtakeover.log (58.47 KB, text/x-log)
2017-05-18 11:06 CEST, Felix Botner
Details
management-console-server.log (129.77 KB, text/x-log)
2017-05-18 11:06 CEST, Felix Botner
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Felix Botner univentionstaff 2017-04-13 10:53:59 CEST
agement-console/1116-1492073147535.socket', '-d', '2', '-l', 'de_DE.UTF-8']
13.04.17 10:46:51.581  MAIN        ( PROCESS ) : running: ['/usr/sbin/univention-management-console-module', '-m', 'adtakeover', '-s', '/var/run/univention-management-console/1116-1492073211581.socket', '-d', '2', '-l', 'de_DE.UTF-8']
13.04.17 10:47:11.106  MAIN        ( WARN    ) : Client: _handle: received an unknown response: 149207323036506-867
13.04.17 10:47:11.107  MAIN        ( ERROR   ) : Module 'adtakeover' ran into error:
13.04.17 10:47:11.157  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 273, in step
    not __sockets[ cond ][ fd ]( sock_obj ):
  File "/usr/lib/pymodules/python2.7/univention/management/console/protocol/client.py", line 333, in _recv
    self._handle(response)
  File "/usr/lib/pymodules/python2.7/univention/management/console/protocol/client.py", line 358, in _handle
    self.signal_emit('error', UnknownRequestError())
  File "/usr/lib/pymodules/python2.7/notifier/signals.py", line 75, in signal_emit
    self.__signals[ signal ].emit( *args )
  File "/usr/lib/pymodules/python2.7/notifier/signals.py", line 41, in emit
    cb( *args )
  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 610, in _mod_error
    self.__processes[module_name].invalidate_all_requests(status=exc.args[0], message=exc.args[1])
IndexError: tuple index out of range

Happened two times now (UCS 4.2)

Opened an UMC module and suddenly UMC said the session is no longer valid and redirected me to the login page. The login fails with

 The Univention Management Console Server is currently not running. 

A restart of univention-management-console-server solved it for me.
Comment 1 Felix Botner univentionstaff 2017-04-13 14:48:49 CEST
i get this very often during the ad-takeover
Comment 2 Felix Botner univentionstaff 2017-05-18 11:06:10 CEST
Created attachment 8861 [details]
management-console-module-adtakeover.log

again and again, always with the takeover module

i have now debug=4 logs for the server and the module
Comment 3 Felix Botner univentionstaff 2017-05-18 11:06:29 CEST
Created attachment 8862 [details]
management-console-server.log
Comment 4 Florian Best univentionstaff 2017-05-18 16:24:26 CEST
I have a reliable way to reproduce this error:

Execute the following command in a shell:
# while true; do curl http://Administrator:Univention.1@localhost/univention/command/adtakeover/progress & sleep 0.1; done

During this command execute two or three times immediately after another the following command:

# curl http://Administrator:Univention.1@localhost/univention/command/adtakeover/connect -H 'Content-Type: application/json' -d '{"options": {"ad_username": "Administrator", "ad_password": "univention", "ip": "10.200.27.112"}}'

This will cause the UMC-Server crash.
The bug is triggered by wrong error handling in combinations with threads in the adtakeover module. The module process somehow ends itself which causes that all request infos are gone but the state machine/socket buffer still contains one response which can't be mapped to any request anymore causing this exception.

univention-management-console.yaml:
r79429 | YAML Bug #44365

univention-management-console (9.0.80-14):
r79428 | Bug #44365: fix crashing of UMC server during error handling
Comment 5 Felix Botner univentionstaff 2017-05-22 12:03:08 CEST
OK - univention-management-console.yaml
OK - i still get an "error" but at least the umc server handles this now by 
     itself (restarts the module)

22.05.17 11:59:40.128  MAIN        ( ERROR   ) : Module 'adtakeover' ran into error: (500, 'Received an unknown response.')
22.05.17 11:59:40.128  MAIN        ( WARN    ) : Invalidating all pending requests 149544718009199-2380
22.05.17 11:59:40.130  MAIN        ( WARN    ) : Module process adtakeover died (pid: 19772, exit status: -1, signal: -1, status: -1)
22.05.17 11:59:40.131  MAIN        ( WARN    ) : Cleaning up requests
22.05.17 11:59:40.131  MAIN        ( WARN    ) : Remove inactivity timer
22.05.17 11:59:40.131  MAIN        ( WARN    ) : Client: _handle: received an unknown response: 149544718009199-2380
22.05.17 11:59:40.131  MAIN        ( ERROR   ) : Module 'adtakeover' ran into error: (500, 'Received an unknown response.')
22.05.17 11:59:42.204  MAIN        ( PROCESS ) : running: ['/usr/sbin/univention-management-console-module', '-m', 'adtakeover', '-s', '/var/run/univention-management-console/18734-1495447182203.socket', '-d', '2', '-l', 'de_DE.UTF-8']
22.05.17 11:59:53.941  MAIN        ( WARN    ) : Client: _handle: received an unknown response: 149544719381181-2399
22.05.17 11:59:53.941  MAIN        ( ERROR   ) : Module 'adtakeover' ran into error: (500, 'Received an unknown response.')
22.05.17 11:59:53.942  MAIN        ( WARN    ) : Invalidating all pending requests 149544719381848-2400
22.05.17 11:59:53.944  MAIN        ( WARN    ) : Module process adtakeover died (pid: 19781, exit status: -1, signal: -1, status: -1)
22.05.17 11:59:53.944  MAIN        ( WARN    ) : Cleaning up requests
22.05.17 11:59:53.944  MAIN        ( WARN    ) : Remove inactivity timer
22.05.17 11:59:53.945  MAIN        ( WARN    ) : Client: _handle: received an unknown response: 149544719381848-2400
22.05.17 11:59:53.945  MAIN        ( ERROR   ) : Module 'adtakeover' ran into error: (500, 'Received an unknown response.')
22.05.17 11:59:56.005  MAIN        ( PROCESS ) : running: ['/usr/sbin/univention-management-console-module', '-m', 'adtakeover', '-s', '/var/run/univention-management-console/18734-1495447196005.socket', '-d', '2', '-l', 'de_DE.UTF-8']
Comment 6 Janek Walkenhorst univentionstaff 2017-06-15 17:58:08 CEST
<http://errata.software-univention.de/ucs/4.2/40.html>