Univention Bugzilla – Bug 33622
UMC crashes with Traceback: IndexError: list index out of range
Last modified: 2021-06-23 07:29:08 CEST
In one of our UCS installations the umc crashes two or three times every week. 28.11.13 14:18:11.834 MAIN ( INFO ) : Passing new request to running module computerroom 28.11.13 14:18:11.834 PROTOCOL ( INFO ) : Sending UMCP COMMAND REQUEST 138564469175637-964 28.11.13 14:18:11.834 PARSER ( INFO ) : UMCP RESPONSE 138564469126989-960 parsed successfully 28.11.13 14:18:11.834 PROTOCOL ( INFO ) : Received UMCP RESPONSE 138564469126989-960 28.11.13 14:18:11.835 PARSER ( PROCESS ) : Attribute status just available for MIME type application/json 28.11.13 14:18:11.835 PARSER ( PROCESS ) : Attribute status just available for MIME type application/json 28.11.13 14:18:11.866 PARSER ( INFO ) : The message body is not complete: 65479 of 145622 bytes 28.11.13 14:18:11.876 PARSER ( INFO ) : The message body is not complete: 131015 of 145622 bytes 28.11.13 14:18:11.887 PARSER ( INFO ) : UMCP RESPONSE 138564469135276-961 parsed successfully 28.11.13 14:18:11.887 PROTOCOL ( INFO ) : Received UMCP RESPONSE 138564469135276-961 28.11.13 14:18:11.887 PARSER ( PROCESS ) : Attribute status just available for MIME type application/json 28.11.13 14:18:11.887 PARSER ( PROCESS ) : Attribute status just available for MIME type application/json 28.11.13 14:18:11.918 PARSER ( INFO ) : The message body is not complete: 65479 of 353405 bytes 28.11.13 14:18:11.928 PARSER ( INFO ) : The message body is not complete: 131015 of 353405 bytes 28.11.13 14:18:11.939 PARSER ( INFO ) : The message body is not complete: 196551 of 353405 bytes 28.11.13 14:18:11.949 PARSER ( INFO ) : The message body is not complete: 262087 of 353405 bytes 28.11.13 14:18:11.960 PARSER ( INFO ) : The message body is not complete: 287943 of 353405 bytes 28.11.13 14:18:11.981 PARSER ( INFO ) : UMCP RESPONSE 138564469146776-962 parsed successfully 28.11.13 14:18:11.981 PROTOCOL ( INFO ) : Received UMCP RESPONSE 138564469146776-962 28.11.13 14:18:11.981 PARSER ( PROCESS ) : Attribute status just available for MIME type application/json 28.11.13 14:18:11.981 PARSER ( PROCESS ) : Attribute status just available for MIME type application/json 28.11.13 14:18:11.982 MAIN ( ERROR ) : Traceback (most recent call last): File "/usr/sbin/univention-management-console-server", line 209, in <module> umc_daemon.do_action() File "/usr/lib/pymodules/python2.6/daemon/runner.py", line 186, in do_action func(self) File "/usr/lib/pymodules/python2.6/daemon/runner.py", line 131, in _start self.app.run() File "/usr/sbin/univention-management-console-server", line 192, in run notifier.loop() File "/usr/lib/pymodules/python2.6/notifier/nf_generic.py", line 284, in loop step() File "/usr/lib/pymodules/python2.6/notifier/nf_generic.py", line 271, in step not __sockets[ cond ][ fd ]( sock_obj ): File "/usr/lib/pymodules/python2.6/univention/management/console/protocol/client.py", line 316, in _recv recv = response.parse( recv ) File "/usr/lib/pymodules/python2.6/univention/management/console/protocol/message.py", line 227, in parse current_length = len( lines[ 1 ] ) IndexError: list index out of range The debug level is allready on 5. Are there Any ways to get more information to fit it in this bug post? We are on errata level 183, and dont't want to make updates unless theres no other way. It's also not possible to trigger this traceback, as it happens randomly.
Created attachment 5685 [details] fix header parsing of UMCP message.py Hello, thank you for your bug report! I could trigger this error as well. The cause for this (probably) seems to be an error when displaying screenshots of students in the computerroom module. To further investigate this some more information would be useful: the logfiles management-console-module-computerroom.log, management-console-web-server.log and some more context from management-console-server.log (with UCR umc/server/debug/level=4 and umc/module/debug/level=4). ________ technical information: It seems that the UMCP header is very long and therefore not send in one chunk (or maybe the body doesn't exists at all?). I can reproduce the problem by simply doing: echo -en 'REQUEST/1/2/application/json: AUTH' | sslify | nc 127.0.0.1 6670 However, from the log I can see that the computerroom module is used with a command which does not use JSON. So it can be caused either by the UMCP-Commands "computerroom/vnc", "computerroom/screenshot" or by a malformed request.
I uploaded a tar file with the requested log files to upload.univention.de: upload_yvm5IH.tar The Problem occured on the 28.11.13 around 14:18.
Created attachment 5686 [details] customer logfile upload_yvm5IH.tar
The patch seems to help in the customer environment. Please prepare it for the next errata updates.
(In reply to Roman Dietiker from comment #2) > I uploaded a tar file with the requested log files to upload.univention.de: > upload_yvm5IH.tar > > The Problem occured on the 28.11.13 around 14:18. Which UCS version do you use? 3.1 or 3.2?
The patch has been applied (slightly adapted to also allow empty bodies). 2014-01-30-univention-management-console.yaml QA: the following still works ;) send() { printf "$1" | socat -t1 stdin openssl:localhost:6670,verify=0 } send 'REQUEST/1/2/application/json: SET\n{}' send 'REQUEST/1/2/application/json: SET\n{}REQUEST/2/2/application/json: SET\n{}' send 'REQUEST/1/0/foo/bar: SET\n' send "$(python -c 'print "REQUEST/1/65536/foo/bar: SET\n" + "a"*65536')" doesn't break anymore: send 'REQUEST/1/2/application/json: AUTH'
Another fix, which allows the UMCP header also to be send in chunks has been commitet. YAML adapted: univention-management-console 6.0.24-3.776.201402041249
VERIFIED, this traceback cannot happen anymore. The error occurred in computerroom/screenshot. The Response string did not contain a '\n'. I was unable to reproduce this in "real life", though. Message._formattedMessage: return '%s/%s/%d/%s: %s %s\n%s' % ( type, _id, len( data ), mimetype, command, args, data ) There is no way how a \n could not be in there, except two cases: (1) Very long header (> 65536 bytes) up to the "\n" -> more or less impossible, as the response in computerroom/screenshot is well defined (2) The socket sends multiple responses at once, the client handles them but the last one is only read up to the " %s %s" and cut just before "\n" I could not observe this behaviour: The socket sends one response at a time. Anyway, the code is better now and should handle (2) (whether this happens or not). If this error occurs again after this patch, we have to rework. Maybe the network even forgot some bytes? In this case we would have to add a checksum?
(In reply to Dirk Wiesenthal from comment #8) > Maybe the network even forgot some bytes? In this case we would have to add > a checksum? Afaik this should not be possible because TCP already has a checksum.
http://errata.univention.de/ucs/3.2/49.html