Python logger not respecting setLevel?

Question

I've spent a bit of time looking through the site at Python logger questions hoping my would be resolved there. I've set up a logger with two stream handlers that have both different formats and levels of logging, here's a functional snippet from my codebase:

import os
import time
import logging

LOG_LEVELS = [logging.ERROR, logging.WARNING, logging.INFO, logging.DEBUG]
TEST_RESULT_LEVELV_NUM = 51

# http://stackoverflow.com/a/11784984/196832
def status(self, message, *args, **kws):
    self._log(TEST_RESULT_LEVELV_NUM, message, args, **kws)

logging.addLevelName(TEST_RESULT_LEVELV_NUM, "RESULT")
logging.Logger.result = status


def setup_logging(level=0, quiet=False, logdir=None):
    logger = logging.getLogger('juju-test')
    ffmt = logging.Formatter('%(asctime)s %(name)s %(levelname)-8s: %(message)s')
    cfmt = logging.Formatter('%(name)s %(levelname)s: %(message)s')
    #logger.setLevel(0)

    if level >= len(LOG_LEVELS):
        level = len(LOG_LEVELS) - 1

    if logdir:
        if not os.path.exists(logdir):
            os.makedirs(logdir)
        logfile = os.path.join(logdir, 'juju-test.%s.log' % int(time.time()))
        fh = logging.FileHandler(logfile)
        # Always at least log to INFO for file, unless DEBUG is requested
        fh.setLevel(LOG_LEVELS[level if level >= 2 else 2])
        fh.setFormatter(ffmt)
        logger.addHandler(fh)

    if not quiet:
        ch = logging.StreamHandler()
        ch.setLevel(LOG_LEVELS[level])
        ch.setFormatter(cfmt)
        logger.addHandler(ch)

    return logger

I've been using an argparse to feed this, but for testing purposes if you feed the following to function:

logger = setup_logging(level=1, logdir="/tmp/oofrab/")
logger.info('Informative!')
logger.warn('Whoa buddy!')
logger.error('Look what you did.')
logger.result("They told me not to make a custom logging level, I'll show them!")
logger.debug('Lots of bugs, man')

I'd expect to see status, error, and warn in the console. Then status, error, warn and info in the log. However, I only see down to warn in both console and log file, despite selecting logging.INFO (key 2 in the LOG_LEVELS list) for the file handler. Is this expected?

I'm not using basicConfig or anything else when building the logger, why can't I have these two custom levels?

Answer 1

Apparently, logging.NOTSET does not mean "All levels", but rather defaults. So setting the parent logger to level 0 does only reverts it to it's default accepted levels. That being said, if I set logger.setLevel to logging.DEBUG that essentially sets logging to accept ALL levels then passes filtering on to the various handlers to filter further.

To get around this (and potential custom log levels) I've set the initial logger level to 1