Simple logging example doesn't work!

Chris Torek nospam at torek.net
Tue Oct 19 11:59:18 CEST 2010


>On Oct 18, 10:45 pm, "robinsieb... at gmail.com" <robinsieb... at gmail.com>
>wrote:
>> If I setlogging.basicConfig() call tologging.INFO, then I see info
>> messages in the logfile. I only want to see error messages in the
>> logfile.

I am not sure how good the documentation is (having not gone back
to look at it) but I had the same problem when I first started using
the logging module for a server.  Vinay Sajip's recipe below is
correct, the only thing missing is "why it is correct":

In article <0945c1e3-f575-4940-8f2c-0374308a366e at j18g2000yqd.googlegroups.com>
Vinay Sajip  <vinay_sajip at yahoo.co.uk> wrote:
>What you need to do is,
>
>1. Set the root logger's level to INFO. That's because you want at
>least INFO messages to go somewhere.
>2. Don't use basicConfig(), but instead create a console handler and a
>file handler explicitly.
>3. Set the file handler's level to ERROR, so only ERROR messages and
>higher go to the file.
>4. Set the console handler's level to INFO, so INFO messages and
>higher go to console.

The reason for step 2 (avoid logging.basicConfig()) is that
basicConfig() creates a handler that goes to sys.stderr.  There is
no way to adjust that handler.  (Well, it is on a list of handlers
that you could peek into, but that seems ... unwise.)

>If you need anything more involved (for example, you ONLY want INFO
>messages to be shown on the console) you'll need to set up a suitable
>Filter and add it to the console handler to filter out messages you
>don't want. See the logging docs for more info on Filters.

Here's a moderately complex example that is full of some bad coding
practices :-) but shows how to do some fancy things.  I snipped it
out of a real program, so there are parts that probably look kind
of whacky but have some real purpose; other parts that look whacky
are because I wrote a lot of this while in early "learning Python"
stages.

    import logging.handlers

    logger = None

[Next is a hack I was experimenting with to sort-of-hide
some globals ... much irrelevant stuff has been snipped out,
so everything you see in "g" here is purely for logging, and
it would make more sense to have a class for logging control
to retain this stuff.  As I said, early code. :-) ]

    class g: pass

    # syslog adds its own time and level stamp.
    g.syslog_format = (
        'nodemgr: %(threadName)s %(message)s'
        ' - %(filename)s/%(funcName)s:%(lineno)d'
    )
    g.stderr_format = '%(levelname)-8s (%(threadName)s) %(message)s'
    g.log_format = (
        '%(asctime)s: ' + g.stderr_format + 
        ' - %(filename)s/%(funcName)s:%(lineno)d'
    )

    # these are actually "log handlers"
    g.file_logger = None
    g.stderr_logger = None
    g.syslog_logger = None

    # Set up initial logger.
    #
    # Although it is labeled "temporary", it persists: it is
    # just its configuration that is "temporary", until we read
    # the config file.
    def init_temporary_logger():
        global logger

        # Get "master" logger with stderr "slave".  Note that we
        # set the master level no higher than DEBUG, otherwise the slaves
        # never see DEBUG-level entries.
        #
        # Can't use basicConfig here as it creates a sys.stderr
        # StreamHandler that we can't adjust later.  Just omit the call:
        #   logging.basicConfig(level = logging.DEBUG, format = ...)
        # which leaves logging.root unset, which is OK.
        nl = logging.getLogger('nodemgr')
        nl.setLevel(logging.DEBUG)
        stream = logging.StreamHandler(sys.stderr)
        stream.setFormatter(logging.Formatter(g.stderr_format))
        stream.setLevel(logging.INFO) # until later
        nl.addHandler(stream)
        g.stderr_logger = stream
        logger = nl

    # Get a syslog "address" given a string.
    def get_syslog_addr(syslog_to):
        # Syslog takes either a host name and optional port, or a path
        # name to a file.  We choose here based on a regexp match.
        m = re.compile('([^/:]+)(:([0-9]+))?$').match(syslog_to)
        if m:
            (host, _, port) = m.groups()
            if port is not None:
                try:
                    port = int(port)
                except ValueError:
                    port = 0
                if port < 1 or port > 65535:
                    logger.error('syslog-to=%s: bad port number', syslog_to)
                    port = 0
            addr = (host, port or logging.handlers.SYSLOG_UDP_PORT)
        else:
            addr = syslog_to
        return addr

    # Update logger based on configuration.
    def update_logger(conf):
        global logger

        # Helper function for swapping out syslog and file loggers.
        def swapout(old, new):
            if old != new and old is not None:
                logger.removeHandler(old)
            if new is not None:
                logger.addHandler(new)
            return new

        # Helper function: is given fd already open to given file name?
        # (Note that this gives you a slightly stale answer, in that the
        # name to underlying file mapping can change in the presence of
        # a rename.  Do not use this for security-issue operations.)
        def fd_is_open_to(fileno, filename):
            try:
                s2 = os.stat(filename)
            except OSError:
                return False
            s1 = os.fstat(fileno)
            return s1.st_dev == s2.st_dev and s1.st_ino == s2.st_ino

        errs = False

        # Configure our logs as directed.
        logconf = conf['logging']

        # First, adjust stderr output level.  We deliberately do
        # this before changing other log handers, so that new debug
        # messages printed here can be seen.  (Maybe should do "raise"
        # now and "lower" later, but does not seem worth the effort.)
        level = logging.getLevelName(logconf['stderr-level'].upper())
        g.stderr_logger.setLevel(level)

        # Gripe about old unsupported config, if needed.
        if conf['USE-FAST-LOGGER']:
            logger.error('FAST logger no longer supported')
            errs = True

        # Now set up syslog logger, if any.
        syslog_to = logconf['syslog-to']
        if syslog_to:
            # Might be nice to remember previous syslog-to (if any)
            # and not create and delete handler if unchanged.  (But
            # see comments elsewhere within this function.)
            addr = get_syslog_addr(syslog_to)
            logger.debug('syslog to: %s' % str(addr))
            try:
                sh = logging.handlers.SysLogHandler(addr,
                    logging.handlers.SysLogHandler.LOG_DAEMON)
                sh.setFormatter(logging.Formatter(g.syslog_format))
            except IOError, e:
                logger.error('syslog-to: %s', e)
                errs = True
                sh = g.syslog_logger
            level = logging.getLevelName(logconf['syslog-level'].upper())
            if sh:
                sh.setLevel(level)
        else:
            logger.debug('syslog logging suppressed')
            sh = None

        # And file logger, if any.
        filepath = logconf['file']
        if filepath:
            if not os.path.isabs(filepath):
                newpath = os.path.join(conf['NODEMGR-BASE-PATH'], filepath)
                logger.warning('logging file=%s: relative path converted to %s',
                    filepath, newpath)
                filepath = newpath
            logger.debug('filelog to: %s' % str(filepath))
            mode = logconf['mode']
            maxsize = logconf['max-size']
            try:
                maxsize = utils.string_to_bytes(maxsize)
            except ValueError:
                logger.error('logging max-size=%s: not a valid size', maxsize)
                maxsize = 1 * 1024 * 1024 # 1 MB
            backup_count = logconf['backup-count']
            level = logging.getLevelName(logconf['level'].upper())
            # If mode is 'w' and maxsize==0, this will open an existing
            # file for writing, truncating it.  If the existing file is
            # our own currently-open log file, this does the wrong thing:
            # we really only want any new level to apply.
            #
            # (If mode is 'a', it's harmless to re-open it, and if
            # maxsize>0 the RotatingFileHandler changes the mode to 'a'.
            # In these cases we want to pick up any max-size or backup-count
            # changes as well.)
            fh = g.file_logger if mode == 'w' and maxsize == 0 else None
            if fh and fd_is_open_to(fh.stream.fileno(), filepath):
                pass # use it unchanged
            else:
                try:
                    fh = logging.handlers.RotatingFileHandler(filepath, mode,
                        maxsize, backup_count)
                    fh.setFormatter(logging.Formatter(g.log_format))
                except IOError, e:
                    logger.error('log to file: %s', e)
                    errs = True
                    fh = g.file_logger
            if fh:
                fh.setLevel(level)
        else:
            logger.debug('file logging suppressed')
            fh = None

        if not errs:
            # Swap out syslog and file loggers last, so that any previous
            # logging about syslog logging and file logging goes to the
            # old loggers (if any).
            g.syslog_logger = swapout(g.syslog_logger, sh)
            g.file_logger = swapout(g.file_logger, fh)

        return errs
-- 
In-Real-Life: Chris Torek, Wind River Systems
Salt Lake City, UT, USA (40°39.22'N, 111°50.29'W)  +1 801 277 2603
email: gmail (figure it out)      http://web.torek.net/torek/index.html



More information about the Python-list mailing list