[Freeipa-devel] [PATCH 53/53] ticket 2022 - modify codebase to utilize IPALogManager, obsoletes logging

[John Dennis]

On 11/16/2011 07:35 AM, Martin Kosek wrote:
> On Tue, 2011-11-15 at 14:41 -0500, John Dennis wrote:
>>
>> --
>> John Dennis<jdennis at redhat.com>
>>
>> Looking to carve out IT costs?
>> www.redhat.com/carveoutcosts/
>
> Hi John,
>
> thanks for your patch, that was a fair amount of work there :-) I tested
> them both and have few comments:
>
> 1) Patch 53 will need rebasing

O.K. will rebase.
>
> 2) Logging for install tools (ipa-server-install, ...) is now broken.
> DEBUG level messages should get to /var/log/ipaserver-install.log even
> when the installer is run without --debug. My
> ipaserver-install.log/ipaserver-uninstall.log was silent when i run just
> `ipa-server-install' without --debug flag

Yes you're right, it's supposed to always log to the file at the debug 
level. Sorry that slipped by, it's a trivial one word fix in 
standard_logging_setup(), done.

> 3) Patch 53 touches most of our Python sources as it changes all
> logging.* calls to log_mgr.root_logger.* calls. I think this may cause
> problems (comment 1 is a good example). For example we may not be able
> to cherry-pick most of new patches from master branch to ipa-2-1 branch
> or other branches that do not use log_mgr.
>
> Additionally, typing "log_mgr.root_logger.*" whenever I want to log
> anything seems a bit awkward to me. These issues are avoidable, however.
> Since all our Python code use just the root_logger, can we just simply
> export root logger in log_manager.py namespace and that import it as
> "logging" in other modules? Then we would save *a lot* of changes across
> all our code. Something like this:
>
> log_manager.py:
> ---------------
>   log_mgr = IPALogManager()
>   log_mgr.configure(dict(default_level='error',
>                          handlers=[dict(name='console',
>                                         stream=sys.stderr)]),
>                     configure_state='default')
> +root_logger = log_mgr.root_logger
>
> ipa-server-install:
> -------------------
> +from ipapython.log_manager import root_logger as logginng
>
> ...
> # now, all logging will work as usual:
> logging.error('Some files have not been restored, see /var/lib/ipa/sysrestore/sysrestore.index')

Cherry picking patches between branches with out performing any editing 
to apply the patch is a nice goal but perhaps not realistic. However 
you're absolutely right this change introduces an extra step during 
patch/rebase.

A larger question is should we continue to support the idea of having 
log functions hung off a module name. Here's my thinking on that. But 
skip to item 3 if you want a compromise solution.


1) I'm a bit concerned that co-opting or borrowing the logging module 
name and using it for an entirely different purpose. Importing the name 
"logging" and not have it be the Python logging module as most Python 
programmers would be the source of needless confusion. Personally I 
think I would be annoyed if someone had played that game because nothing 
would be as I expect. The name "logging" implies the logging module with 
all sorts of names, constants, objects, classes, sub-modules, etc. 
associated with it, none of that would retain any of it's conventional 
meaning. I much prefer clarity and to call something what it is and not 
obfuscate for temporary expediency.

2) The current Python logging implementation is broken IMHO and was the 
source of some of our problems, I'm not sure I want to perpetuate that. 
It exported a set of "convenience" functions bound to a global. It made 
using the logging module easier to use via globals but at the expense of 
all sorts of conflicts when more than one client of logging tried to 
manipulate the same shared global objects.

The logging.debug(), etc. names are a bogus mapping of a top level 
module symbol to a bound method of a specific instantiated object, an 
object available externally only by calling a defined API to retrieve 
that object from singleton manager by name. To my mind this is the 
classic abuse of globals every textbook warns against. It's just bad 
programming best avoided IMHO.

Why is it O.K. to have a global log_mgr object for IPA?

   a) Because it belongs to us, it's not shared with every piece of
      Python code which imports the logging module.

   b) It's not abusing a top level module symbol to be a short circuit
      reference into some other instantiated object. The root logger
      belongs to the log_mgr instance shared by loaded IPA components.
      Think of it as an IPA singleton.

3) Can we have a shorter name as a compromise? Sure, I have no problems
    with that. We already have the log_mgr as a single imported instance.
    I don't see why we couldn't have also import the symbol
    "root_logger" which is log_mgr.root_logger. I'm not keen on shorting
    the name much more, for instance to "logger" because that's too
    generic and obscures the fact it's the root logger, an important
    distinction to maintain.

    An other option would be to have a LogManager object export the
    debug(), info(), error(), critical(), & exception() methods where
    they are bound to the LogManager's root_logger instance. This is
    somewhat akin to what the standard Python logging module, except
    they performed the binding on the module level and not on an
    instance (the source of many problems). Those log methods *must*
    be bound to a Logger object as such I'm not entirely keen on
    binding them to a LogManager instance because once again you
    end up providing an abused short cut which hides what is really
    going on. I think it would benefit programmers if they knew they
    were logging to a Logger and if so which one, because after all
    once you try to customize things like "which loggers emit which
    which messages" it would be really helpful to know you're dealing
    with a Logger and which one it is and not obscure which one it is
    to shorten the reference to it as a convenience via some short cut.
    But if there is a consensus I could bend on this issue.

    That means we could have one of the two (I prefer the first)

    root_logger.debug()

    -or-

    log_mgr.debug() # Not a fan of this because it hides the important
                    # concept of debug() being bound to the root_logger.

    As for:

    logging.debug()

    For the reasons pointed out in 1 I'd like to avoid that kind of
    symbol abuse.


-- 
John Dennis <jdennis at redhat.com>

Looking to carve out IT costs?
www.redhat.com/carveoutcosts/