Univention Bugzilla – Bug 33673
Tracebacks in UMC module init() function are not logged
Last modified: 2015-03-18 12:40:05 CET
I forced a traceback in the init method if the UCR module and could observe the following: > ==> /var/log/univention/management-console-server.log <== > 05.12.13 22:31:42.146 MAIN ( INFO ) : Connected to new module process > 05.12.13 22:31:42.146 PROTOCOL ( INFO ) : Sending UMCP SET REQUEST 138627910214672-5 → this is actually the request during which the init method is invoked > 05.12.13 22:31:42.147 PROTOCOL ( INFO ) : Sending UMCP COMMAND REQUEST 138627910173450-1941 > 05.12.13 22:31:42.147 PROTOCOL ( INFO ) : Sending UMCP COMMAND REQUEST 138627910181606-1942 > > ==> /var/log/univention/management-console-module-ucr.log <== > 05.12.13 22:31:42.147 MAIN ( INFO ) : Incoming connection from > 05.12.13 22:31:42.147 PARSER ( INFO ) : UMCP REQUEST 138627910214672-5 parsed successfully > 05.12.13 22:31:42.148 MODULE ( INFO ) : Received request 138627910214672-5 > 05.12.13 22:31:42.148 PROTOCOL ( INFO ) : Received UMCP SET REQUEST 138627910214672-5 > 05.12.13 22:31:42.148 MODULE ( INFO ) : Setting specified locale (en_US.UTF-8) > 05.12.13 22:31:42.148 MODULE ( INFO ) : Setting user LDAP DN uid=Administrator,cn=users,dc=ucs32,dc=qa > 05.12.13 22:31:42.148 MODULE ( ERROR ) : ### provoking traceback → at this point the error is raised > 05.12.13 22:31:42.149 PROTOCOL ( INFO ) : Sending UMCP RESPONSE 138627910214672-5 → the response contains the traceback > ==> /var/log/univention/management-console-server.log <== > 05.12.13 22:31:42.149 PARSER ( INFO ) : UMCP RESPONSE 138627910214672-5 parsed successfully > 05.12.13 22:31:42.149 PROTOCOL ( INFO ) : Received UMCP RESPONSE 138627910214672-5 > 05.12.13 22:31:42.149 MAIN ( INFO ) : The given response is invalid or not known (138627910214672-5) → usually this entry can be observed in the UMC server log file. The response containing the traceback is ignored as invalid as its ID is not in the list of known requests. Forcing the server to dump the message, we see the traceback: > RESPONSE/138627910214672-5/384/application/json: SET > {"status": 590, "message": "The init function of the module has failed: RuntimeError: ERROR > File \"/usr/lib/pymodules/python2.6/univention/management/console/protocol/modserver.py\", line 222, in handle > self.__handler.init() > File \"/usr/lib/pymodules/python2.6/univention/management/console/modules/ucr/__init__.py\", line 54, in init > raise RuntimeError('ERROR') > "} It would be helpful to see this error message in order to identify problems as in Bug 33627.
> → usually this entry can be observed in the UMC server log file. The response > containing the traceback is ignored as invalid as its ID is not in the list of > known requests. Forcing the server to dump the message, we see the traceback: Yes, internally there is a SET request send to the Moduleprocess (which is no request from the frontend). Shouldn't the moduleprocess exit when init() fails?
(In reply to Florian Best from comment #1) > ... > Shouldn't the moduleprocess exit when init() fails? Well, it would be consistent, otherwise side effects may happen unnoticed or they may happen at a later state which will be difficult to recognize.
A feedback in form of a traceback is now sent to the client if the initialization of a module fails. YAML: 2013-12-13-univention-management-console.yaml
If something went wrong during module initialization (i.e. during "import time"), I get a traceback "ImportError: wizard does not exist" (or something like that). Shortly after that I get a dialogue that the connection is lost and the client is trying to reconnect. Before this change we got "Connection to module process failed". While I like the fact that now a traceback is shown, it is useless in the current form. Please show the correct traceback. Is this "import wizard" really used anywhere or does it only exist to hide the real error? Please also have a look at the dialogue popping up (it better does not!). Maybe it was because I used "?username=Administrator&password=secret"?
*** Bug 28746 has been marked as a duplicate of this bug. ***
(In reply to Dirk Wiesenthal from comment #4) > If something went wrong during module initialization (i.e. during "import > time"), I get a traceback "ImportError: wizard does not exist" (or something > like that). Shortly after that I get a dialogue that the connection is lost > and the client is trying to reconnect. The import of univention.management.console.wizards.$modulename is not used and has been removed. > Before this change we got "Connection to module process failed". While I > like the fact that now a traceback is shown, it is useless in the current > form. Please show the correct traceback. Is this "import wizard" really used > anywhere or does it only exist to hide the real error? This was a typo, the correct traceback is no shown. > Please also have a look at the dialogue popping up (it better does not!). > Maybe it was because I used "?username=Administrator&password=secret"? This is related to the updater module and would have to be fixed there. univention-management-console 6.0.23-1.773.201312131648 univention-management-console-frontend 3.0.152-8.805.201401141007
OK: * Shows up in logs * Is sent to the frontend * Works for ImportError and __init__() and init() * Module dies reasonably fast so that a new one is usable after a temporary (network) error YAML OK
http://errata.univention.de/ucs/3.2/40.html
Fix was in svn r46753 and r47061