Bug 32565 - UMC Server dies when newly installed UDM module uses newly installed UDM syntax
UMC Server dies when newly installed UDM module uses newly installed UDM syntax
Status: CLOSED FIXED
Product: UCS
Classification: Unclassified
Component: UMC (Generic)
UCS 3.1
Other Linux
: P3 normal (vote)
: UCS 3.2
Assigned To: Dirk Wiesenthal
Florian Best
: interim-3
Depends on:
Blocks: 28670 33091
  Show dependency treegraph
 
Reported: 2013-09-11 16:49 CEST by Alexander Kläser
Modified: 2013-11-19 06:43 CET (History)
8 users (show)

See Also:
What kind of report is it?: ---
What type of bug is this?: ---
Who will be affected by this bug?: ---
How will those affected feel about the bug?: ---
User Pain:
Enterprise Customer affected?:
School Customer affected?:
ISV affected?:
Waiting Support:
Ticket number:
Bug group (optional):
Max CVSS v3 score:


Attachments
while True: reload(everything) (6.54 KB, patch)
2013-10-16 22:29 CEST, Dirk Wiesenthal
Details | Diff

Note You need to log in before you can comment on or make changes to this bug.
Description Alexander Kläser univentionstaff 2013-09-11 16:49:47 CEST
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"}
Comment 1 Alexander Kläser univentionstaff 2013-09-11 16:51:14 CEST
Could it be that import_syntax_files() only updates syntax.d/* files?
Comment 2 Arvid Requate univentionstaff 2013-09-11 19:52:06 CEST
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.
Comment 3 Dirk Wiesenthal univentionstaff 2013-09-25 13:24:31 CEST
(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'
Comment 4 Dirk Wiesenthal univentionstaff 2013-10-09 14:26:38 CEST
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'
Comment 5 Dirk Wiesenthal univentionstaff 2013-10-09 14:41:35 CEST
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'
Comment 6 Stefan Gohmann univentionstaff 2013-10-11 19:33:19 CEST
With r43914 I'm unable to join new systems because udm can not be started as Administrator, see Comment #5 for the traceback.
Comment 7 Arvid Requate univentionstaff 2013-10-14 12:18:12 CEST
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.
Comment 8 Alexander Kläser univentionstaff 2013-10-15 09:40:07 CEST
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)
Comment 9 Stefan Gohmann univentionstaff 2013-10-15 21:43:31 CEST
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
Comment 10 Dirk Wiesenthal univentionstaff 2013-10-16 22:29:44 CEST
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.
Comment 11 Dirk Wiesenthal univentionstaff 2013-10-16 23:00:04 CEST
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...
Comment 12 Dirk Wiesenthal univentionstaff 2013-10-16 23:03:47 CEST
Copying all these syntax classes in syntax.d/added_in_ucs32.py should also do the trick (untested).
Comment 13 Alexander Kläser univentionstaff 2013-10-17 10:06:37 CEST
(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?
Comment 14 Dirk Wiesenthal univentionstaff 2013-10-17 22:47:14 CEST
(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.
Comment 15 Florian Best univentionstaff 2013-10-21 16:50:25 CEST
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.
Comment 16 Dirk Wiesenthal univentionstaff 2013-10-21 17:20:31 CEST
(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')
Comment 17 Felix Botner univentionstaff 2013-10-22 17:10:06 CEST
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.
Comment 18 Dirk Wiesenthal univentionstaff 2013-10-29 11:58:14 CET
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).
Comment 19 Philipp Hahn univentionstaff 2013-10-29 18:56:49 CET
(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")
Comment 20 Philipp Hahn univentionstaff 2013-10-29 18:57:51 CET
Doing things by just importing a module is evil!
Comment 21 Dirk Wiesenthal univentionstaff 2013-10-29 19:48:42 CET
#!/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")
Comment 22 Florian Best univentionstaff 2013-10-30 14:38:31 CET
The UMC Server runs after update and is usable (==login+UDM possible).
All failures while updating are catched.

Changelog OK
Comment 23 Stefan Gohmann univentionstaff 2013-11-19 06:43:14 CET
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".