Univention Bugzilla – Bug 32565
UMC Server dies when newly installed UDM module uses newly installed UDM syntax
Last modified: 2013-11-19 06:43:14 CET
A similar problem occurred with Bug 32411 when I updated my machine. This will probably be a generic problem when updating from 3.1-1 to 3.2: ==================== 11.09.13 07:15:32.011 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/sbin/univention-management-console-server", line 142, in _restart self._start() 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/server.py", line 165, in _receive self._handle( state, msg ) File "/usr/lib/pymodules/python2.6/univention/management/console/protocol/server.py", line 279, in _handle state.processor = Processor( *state.credentials() ) File "/usr/lib/pymodules/python2.6/univention/management/console/protocol/session.py", line 207, in __init__ udm_modules.update() File "/usr/lib/pymodules/python2.6/univention/admin/modules.py", line 94, in update os.path.walk(dir, _walk, p) File "/usr/lib/python2.6/posixpath.py", line 236, in walk walk(name, func, arg) File "/usr/lib/python2.6/posixpath.py", line 228, in walk func(arg, top, names) File "/usr/lib/pymodules/python2.6/univention/admin/modules.py", line 78, in _walk m=__import__(mod, globals(), locals(), name) File "/usr/lib/pymodules/python2.6/univention/admin/handlers/settings/udm_syntax.py", line 69, in <module> syntax=univention.admin.syntax.BaseFilename, AttributeError: 'module' object has no attribute 'BaseFilename' 11.09.13 07:15:32.038 MAIN ( PROCESS ) : Processor: dying ==================== +++ This bug was initially created as a clone of Bug #31154 +++ Happened after installation of an app (UCC), which restarts LDAP: UMC asked to restart, but I did not respond for 10 Minutes, so I was logged out automatically. I tried to login again, but although the login dialog disappeared I was not able to restart UMC (dialog.notify("Your session expired, please login again")). So I logged out and tried to login. Screenshot attached. I had to restart UMC on the command line. UMC Error of umcp/auth: {"status": "401 Unauthorized", "message": "No permission -- see authorization schemes"}
Could it be that import_syntax_files() only updates syntax.d/* files?
While tracking the issue down I found what I think is a timing issue in the handling of the bytecompiled pyc files: First I tried to enhance modules.update() by a simple reload(univention.admin.syntax) This first seemed to fix the issue, but only in maybe less than 20 percent of the test runs. The test consisted of a python script which copied a backup of the old syntax.py (without BaseFilename) over the pyshared file. Then, after the initial import of univention.admin.modules, it copied the new version over to pyshared before calling modules.update(). Running the test script with "python2.6 -v" revealed these message in cases of failure: ========================================================================= # /usr/lib/pymodules/python2.6/univention/admin/syntax.pyc has bad mtime /usr/lib/pymodules/python2.6/univention/admin/syntax.py: inconsistent use of tabs and spaces in indentation import univention.admin.syntax # from /usr/lib/pymodules/python2.6/univention/admin/syntax.py # wrote /usr/lib/pymodules/python2.6/univention/admin/syntax.pyc ========================================================================= vs these messages in cases of success: ========================================================================= > # /usr/lib/pymodules/python2.6/univention/admin/syntax.pyc matches /usr/lib/pymodules/python2.6/univention/admin/syntax.py > import univention.admin.syntax # precompiled from /usr/lib/pymodules/python2.6/univention/admin/syntax.pyc ========================================================================= Removing the pyc file reliably fixed the issue, but for my taste that is a bit to much force. As a workaround, I now make the modules.update function inspect the loaded univention.admin.syntax and .hook modules to see if they have been loaded from pyc. If not I bytecompile the source file and reload the module again. Let's see if this also catches the real-life issues of fellow developers.
(In reply to Arvid Requate from comment #2) > Let's see if this also catches the real-life issues of fellow developers. Hmmm... no. Similar (not exactly the same) traceback when updating UCS 3.1 to UCS 3.2 and not restarting UMC immediately, but instead logging in (creating a new session) with another browser. 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/server.py", line 166, in _receive except IncompleteMessageError, e: File "/usr/lib/pymodules/python2.6/univention/management/console/protocol/server.py", line 278, in _handle if not state.processor: File "/usr/lib/pymodules/python2.6/univention/management/console/protocol/session.py", line 213, in __init__ users_module = None File "/usr/lib/pymodules/python2.6/univention/admin/modules.py", line 94, in update if isContainer(m): File "/usr/lib/python2.6/posixpath.py", line 236, in walk walk(name, func, arg) File "/usr/lib/python2.6/posixpath.py", line 228, in walk func(arg, top, names) File "/usr/lib/pymodules/python2.6/univention/admin/modules.py", line 78, in _walk univention.admin.syntax.import_syntax_files() File "/usr/lib/pymodules/python2.6/univention/admin/handlers/settings/ldapacl.py", line 69, in <module> syntax=univention.admin.syntax.BaseFilename, AttributeError: 'module' object has no attribute 'BaseFilename'
py_compile.compile should not be used here. Before: -rw-r--r-- 1 root root 158313 9. Okt 14:19 /usr/lib/pymodules/python2.6/univention/admin/syntax.pyc After (UMC server runs as root and has a specific umask for security reasons): -rw------- 1 root root 159712 9. Okt 14:03 /usr/lib/pymodules/python2.6/univention/admin/syntax.pyc Resulting in Administrator@master250:~$ /usr/sbin/univention-directory-manager --help E: Can`t connect daemon after 30 seconds. Because of IOError: [Errno 13] Permission denied: '/usr/lib/pymodules/python2.6/univention/admin/syntax.pyc'
Does not necessarily have something to do with umask. -rw-r--r-- is sufficient: Administrator@master:~$ /usr/share/univention-directory-manager-tools/univention-cli-server Traceback (most recent call last): File "/usr/share/univention-directory-manager-tools/univention-cli-server", line 43, in <module> import univention.admincli.admin File "/usr/lib/pymodules/python2.6/univention/admincli/admin.py", line 52, in <module> univention.admin.modules.update() File "/usr/lib/pymodules/python2.6/univention/admin/modules.py", line 74, in update py_compile.compile(inspect.getfile(imported_module)) File "/usr/lib/python2.6/py_compile.py", line 135, in compile fc = open(cfile, 'wb') IOError: [Errno 13] Permission denied: '/usr/lib/pymodules/python2.6/univention/admin/hook.pyc'
With r43914 I'm unable to join new systems because udm can not be started as Administrator, see Comment #5 for the traceback.
Ok, the first patch was bogous: While the timing issue is there, it's not the cause of the problem. The real cause of problem was, that the function import_syntax_files did not import syntax.py itself, only the syntax.d subfiles.
Another problem occurred in the UDM UMC module in syntax.py. During the reload, references to syntax classes were rendered invalid. univention-management-console-module-udm (4.0.43-1) unstable; urgency=low . * udm/syntax.py should not statically import syntax classes (Bug #32565)
r45048 breaks the following command: udm computers/windows create \ --set name=x12 \ --set dnsEntryZoneForward=zoneName=deadlock18.local,cn=dns,$ldap_base \ --set ip=10.201.18.12 E: Invalid Syntax: dnsEntryZoneForward: too many arguments
Created attachment 5522 [details] while True: reload(everything) I decided to do the following: Revert what has been done, avoid the situation in which this specific traceback happens in umc-server. univention-directory-manager-modules 9.0.63-1.1129.201310161902 univention-management-console 6.0.18-1.767.201310161934 udm_modules.update() is still prone to this error. One has to be careful when using it. On the other hand: It should happen very rarely that syntax.py and handlers/some/module.py change significantly, i.e. that a new syntax is added and used. To really fix this, one has to reload: * syntax.py * everything in syntax.d/* * the udm module * to be correct: _every_ udm module, at least settings/* and policies/*, who knows what changed? And as one does not really know if something changed one has to do this every time. UMC-UDM has a feature that reloads the module on nearly each request for extended attributes to take effect. This would mean that UMC-UDM would have to reload nearly everything in univention.admin. (Sidenote: it was proposed that one could add: UCR-triggers, UDM-listeners, file watch handlers, to notify anyone when something (might have) changed. While this could reduce performance problems, it adds a lot of complexity) At the same time one has to be very careful with modules in the handlers: Do they have to be reloaded when I reload? mungeddial has to be reloaded in users/user for example. Code that uses the directory-manager has to be careful, too: UMC-UDM imports udm_syntax. If it calls udm_modules.update() it has to reimport udm_syntax itself. And it has to take care that each module that imports udm_syntax is also reimported. Example: umc-udm/umc/python/udm/syntax.py has to be reimported. And, of course: umc-udm/umc/python/udm/syntax.py has to reimport udm_syntax. So the whole process is extremely fragile and costs a lot of time. I do not think that it is worth catching that one rare event when someone updates syntax.py but refuses to restart a running process that updates only the handlers of the directory-manager (namely UMC-server). Such updates will probably take place during release updates. I do not think that anyone will try to use UMC after that without a restart. I patched UMC-server itself to not crash when an updated users/user uses a new syntax not defined on UMC-server startup. So, at least for UMC, this bug is now just: If some/handler is updated and uses a syntax yet unknown, the server will still be able to start new sessions. New sessions get new UDM modules so that new sessions will have up-to-date modules! The only processes that will show tracebacks are umc-udm modules that started before the package update. I vote for embracing that bug. Just for the record, I attached a patch that seems to fix the problem... for univention-directory-manager-modules. UMC-UDM would have to be patched separately.
One last remark for QA: The new umc-server with the patch is available not before a restart. This means that after UCS 3.2 update it may be that the umc-server crashes before it could be restarted. If this is sufficiently bad, a workaround would be: define each new syntax where needed in the handler itself during UCS 3.2 lifetime. diff says: class UCSVersion( string ) class DebianPackageVersion( string ) class BaseFilename( string ) class Base64GzipText( TextArea ) class Base64Bzip2Text( TextArea ) class Base64Bzip2XML( TextArea ) class Base64UMCIcon( TextArea ) class GNUMessageCatalog( TextArea ) class Localesubdirname( string ) class Localesubdirname_and_GNUMessageCatalog( complex ) class ipnetwork(simple) class adGroupType(select) class UCSServerRole( select ) class list_of_hostnames_and_ipadresses_and_networks(simple) class ObjectFlag( select ) Plus whatever is added from now on...
Copying all these syntax classes in syntax.d/added_in_ucs32.py should also do the trick (untested).
(In reply to Dirk Wiesenthal from comment #11) > One last remark for QA: The new umc-server with the patch is available not > before a restart. This means that after UCS 3.2 update it may be that the > umc-server crashes before it could be restarted. Might it be necessary to ship the patch for the UMC server in an erratum?
(In reply to Alexander Kläser from comment #13) > Might it be necessary to ship the patch for the UMC server in an erratum? Not necessary. But helpful.
if the users module cannot be loaded now this will trace afterwards: + if not self.__udm_users_module_initialised: + # initiate the users/user UDM module + udm_modules.init(self.lo, self.po, users_module) + self.__udm_users_module_initialised = True There is a check missing if users_modules is not None.
(In reply to Florian Best from comment #15) > if the users module cannot be loaded now this will trace afterwards: > > + if not self.__udm_users_module_initialised: > + # initiate the users/user UDM module > + udm_modules.init(self.lo, self.po, > users_module) > + self.__udm_users_module_initialised = True > > There is a check missing if users_modules is not None. There is, two lines above that: if not users_module: raise udm_errors.base('UDM module users/user could not be initiated')
during the update to ucs 3.2 the udm-cli is unusable -> /usr/share/univention-directory-manager-tools/univention-cli-server Traceback (most recent call last): File "/usr/share/univention-directory-manager-tools/univention-cli-server", line 43, in <module> import univention.admincli.admin File "/usr/lib/pymodules/python2.6/univention/admincli/admin.py", line 52, in <module> univention.admin.modules.update() File "/usr/lib/pymodules/python2.6/univention/admin/modules.py", line 92, in update os.path.walk(dir, _walk, p) File "/usr/lib/python2.6/posixpath.py", line 236, in walk walk(name, func, arg) File "/usr/lib/python2.6/posixpath.py", line 228, in walk func(arg, top, names) File "/usr/lib/pymodules/python2.6/univention/admin/modules.py", line 76, in _walk m=__import__(mod, globals(), locals(), name) File "/usr/lib/pymodules/python2.6/univention/admin/handlers/uvmm/info.py", line 97, in <module> syntax=udm_syntax.UvmmProfiles, AttributeError: 'module' object has no attribute 'UvmmProfiles' udm_syntax.UvmmProfiles was added in UCS 3.2.
stop_udm_cli_server in postinst of univention-directory-manager-modules (9.0.72-2) Plus: postinst of univention-management-console-module-apps could raise that exception: It executes some python which imports the app center module. This imports the umc-server modules and there a udm_modules.update() is executed (during "import time" due to my fix for umc-server). Now I also catch AttributeError there. univention.management.console.protocol.session may not be fully functional but this is most probably not needed when using debian maintainer scripts. univention-management-console 6.0.21-1.770.201310291155 BTW: I added a fallback logging mechanism if log_init is not called (which is not the case for anything except the scripts to start umc-server and umc-modules).
(In reply to Dirk Wiesenthal from comment #18) > BTW: I added a fallback logging mechanism if log_init is not called (which > is not the case for anything except the scripts to start umc-server and > umc-modules). r45656 breaks any application using Python logging and importing something from univention.management.console.modules as currently is required for Bug #28670: /usr/share/pyshared/univention/management/console/modules/__init__.py from ..log import MODULE /usr/share/pyshared/univention/management/console/log.py logging.basicConfig(format='%(asctime)s.%(msecs)03d %(component)-11s ( %(level)-7s ) : %(message)s', datefmt='%d.%m.%y %H:%M:%S', level=10) Since logging is now basic-configured, all future calls to baseConfig() are ignored, which breaks the following simple example program: #!/usr/bin/python import sys import univention.management.console.modules import logging logging.basicConfig(stream=sys.stdout, level=logging.DEBUG) logger = logging.getLogger("root") logger.fatal("You broke it")
Doing things by just importing a module is evil!
#!/usr/bin/python import sys from univention.management.console.log import MODULE import logging logging.basicConfig(stream=sys.stdout, level=logging.DEBUG) logger = logging.getLogger("root") logger.fatal("I am very sorry.") MODULE.process("Fixed in univention-management-console 6.0.21-2.771.201310291945")
The UMC Server runs after update and is usable (==login+UDM possible). All failures while updating are catched. Changelog OK
UCS 3.2 has been released: http://docs.univention.de/release-notes-3.2-en.html http://docs.univention.de/release-notes-3.2-de.html If this error occurs again, please use "Clone This Bug".