the root logger is not got right

[yong sheng gong]

def _setup_logging_from_conf(product_name):
    log_root = getLogger(product_name).logger -> log_root is not truly root logger here. so the handler removing will fail to work if we already have default handlers in root logger.
    for handler in log_root.handlers:
        log_root.removeHandler(handler)
# I think we should prevent log_root to propagate by log_root.propagate = 0, this will make the product logger work as root for our loggers in other codes
    if CONF.use_syslog:
        facility = _find_facility_from_conf()
        syslog = logging.handlers.SysLogHandler(address='/dev/log',
                                                facility=facility)
        log_root.addHandler(syslog)

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.openstack.org/15085

[Mark McLoughlin (markmc)]

Ok, I think what you say makes some sense but it would be helpful if you could explain the specific use case you're thinking of

e.g. if you wanted all plugins in the quantum server to set up their own root logger, then each plugin would call log.setup() with its own product name and you would want a different root logger per plugin

Is that the use case here? Or something else? Please explain in detail

[yong sheng gong (gongysh)]

logger.get(__name__) will add streamhandler to RootLogger via basicconfig().
For example:
test.a.py:
LOG = logging.getLogger(__name__)
test.b.py:

from test import a #this line will active RootLogger and add stdout streamhandler to it.
from quatum.openstack.common import log as logging

LOG = logging.getLogger(__name__)
if __name__ =' __main__':
    logging.setup('test')
   LOG.debug('I just want to log to a file, but it will go to stdout too since the True RootLogger has a streamhandler set')
#after this point, even I just want to log into file in test.conf , but the RootLogger has stdout streamhandler set, the log will go to stdout too.

[yong sheng gong (gongysh)]

 just want the config file can control all the log output in the product logger umbrella.

[Doug Hellmann (doug-hellmann)]

Simply asking for a named logger should not have the side effect of adding a logging handler. If that is really happening, we should remove that behavior instead of forcing propagate to be false.

[Jason Kölker (jason-koelker)]

Both logging.basicConfig and _setup_logging_from_conf more or less do the same thing. If you want to use them together you should call _setup_logging_from_conf with "None" to have it act on the root logger instead of the product logger. Moreover if you want to control it via the config file then pass a --log-config=/path/to/file option and _setup_logging_from_conf will never be called and the logging module will be configured solely from the logging config.

[yong sheng gong (gongysh)]

forcing propagate can make sure def setup(product_name): work as it name hints.
After this function is called, our logger which are sub loggers of product_name should log as this function sets.

If we don't force it and any other third party codes have another handlers settings, such as stdout stream, all the loggers in our product will print the logs on stdout besides the handlers set up in this function.

Is my observation right?

[Michael Basnight (hubcap)]

calling logging.setup(None) manages to work around this issue

[Doug Hellmann (doug-hellmann)]

We're seeing issues with logging from non-openstack libraries in the ceilometer project because the "root" logger being initialized is the project-specific logger instead of the true root. I like Michael's proposed fix to do the setup on the actual root logger by specifying None.

[Mark McLoughlin (markmc)]

Ok, sounds like the issue is confirmed and we have an idea for a fix

[Robert Kukura (rkukura)]

This is a fairly critical issue for any code using stevedore. I've had to hack a work-around to debug issues preventing drivers from loading with Quantum's ML2 plugin, but I'm not familiar enough with python logging to know if my hack is the proper fix. The hack that seems to work for me is to change quantum/common/config.py to contain:

def setup_logging(conf):
    """
    Sets up the logging options for a log with supplied name

    :param conf: a cfg.ConfOpts object
    """
# product_name = "quantum"
    product_name = None
    logging.setup(product_name)
    log_root = logging.getLogger(product_name).logger
    log_root.propagate = 0
    LOG.info(_("Logging enabled!"))

I noticed that the conf param isn't used, and with this hack, neither is the product_name, so maybe something more generic would do the job.

[yong sheng gong (gongysh)]

Robert Kukura,
what is the problem which preventing drivers from loading if we use quantum as product name?

too keep conf parameter is for being compatible with existing codes.

[Robert Kukura (rkukura)]

Yong,

The logging itself is not preventing drivers from loading. Sorry if I was unclear. The problem is that messages that the stevedore library, which ml2 uses for loading drivers, tries to log are not logged. If a driver cannot be loaded, the details on why it couldn't be loaded should be logged but instead are lost. During development, syntax errors, missing abstract method implementations, etc., are common reasons a driver cannot be loaded, and the trace info that stevedore tries to log would be really helpful.

-Bob

[yong sheng gong (gongysh)]

Bob
I am glad to hear the ML2 bp's progress. I think we can use the None solution.

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.openstack.org/24203

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/24203
Committed: http://github.com/openstack/oslo-incubator/commit/9fe688a412d910e29fdf97fd0f97a7f815db6c8f
Submitter: Jenkins
Branch: master

commit 9fe688a412d910e29fdf97fd0f97a7f815db6c8f
Author: Zhiteng Huang <email address hidden>
Date: Wed Mar 13 00:27:48 2013 +0800

    Initialize root logger in _setup_logging_from_conf()

    log.setup() doesn't really initialize root logger, therefore logging
    in 3rd party library such as stevedore doesn't work properly. This
    patch enable root logger initialization.

    Fix bug: # 1073241

    Change-Id: I6fa41b2ba41ff97ad0280f8774a26887d294423e