What Is the Point of Setlevel in a Python Logging Handler

What is the point of setLevel in a python logging handler?

It allows finer control. By default the root logger has WARNING level set, this means that it wont print messages with lower level(no matter how the handlers' levels are set!). But, if you set the root logger's level to DEBUG, indeed the message get sent to the log file:

import logging
import logging.handlers

a = logging.getLogger('myapp')
a.setLevel(logging.DEBUG)   # set root's level
h = logging.handlers.RotatingFileHandler('foo.log')
h.setLevel(logging.DEBUG)
a.addHandler(h)
print a.getEffectiveLevel() 
a.debug('foo message')
a.warn('warning message')

Now, image that you want to add a new handler that doesn't record debug information.
You can do this by simply setting the handler logging level:

import logging
import logging.handlers

a = logging.getLogger('myapp')
a.setLevel(logging.DEBUG)   # set root's level

h = logging.handlers.RotatingFileHandler('foo.log')
h.setLevel(logging.DEBUG)
a.addHandler(h)

h2 = logging.handlers.RotatingFileHandler('foo2.log')
h2.setLevel(logging.WARNING)
a.addHandler(h2)

print a.getEffectiveLevel() 
a.debug('foo message')
a.warn('warning message')

Now, the log file foo.log will contain both messages, while the file foo2.log will only contain the warning message. You could be interested in having a log file of only error-level messages, then simply add a Handler and set its level to logging.ERROR, everything using the same Logger.

You may think of the Logger logging level as a global restriction on which messages are "interesting" for a given logger and its handlers. The messages that are considered by the logger afterwards get sent to the handlers, which perform their own filtering and logging process.

logging level vs handler level

logger is higher than handler. You can image that handler is a filter. For example, you have one logger with two handlers:

myLogging = logging.getLogger('myOp')
myLogging.setLevel(10)

hdlr1 = xxx
hdlr2 = xxx
hdlr1.setLevel(20)
hdlr2.setLevel(30)

myLogging.addHandler(hdlr1)
myLogging.addHandler(hdlr2)

In this case, logger itself will log 10+,hdlr1 will log more information than hdlr2(20+ vs 30+).

And back to your case, although you have set hdlr.setLevel(10), but suppose your logger's level is 20, this is like an inverted triangle.

Unable to set different logging levels for two logging handlers in python

Okay, to answer your first question,

Logger objects have a threefold job. First, they expose several
methods to application code so that applications can log messages at
runtime. Second, logger objects determine which log messages to act
upon based upon severity (the default filtering facility) or filter
objects. Third, logger objects pass along relevant log messages to all
interested log handlers.

So in your application, you need that some level messages get logged to a file, and some are displayed on console. So to do that, you would first need to create a logger object, specify the lowest severity (ie. the default filtering facility as mentioned in doc above) that will be dispatched to the appropriate destination (ie. first to the handler, then right handlers' destination).

It is like you are saying to the logger object, your handlers will be handling log messages only above this level. In case you do not specify it, or you give a level above which the handlers are going to dispatch, then that log message may not be dispatched to the handler because the logger object did not receive it in the first place. Make sense?

So that means if you are going to be using handlers, you are required to setLevel() for logger first, since that is the initial filter/point where the log messages are dispatched to. Later, the logger dispatches it to respective handlers.

For your next question,

I ran your code after adding the following lines at the bottom:

logger.debug('Quick zephyrs blow, vexing daft Jim.')
logger.info('How quickly daft jumping zebras vex.')
logger.warning('Jail zesty vixen who grabbed pay from quack.')
logger.error('The five boxing wizards jump quickly.')

and I am getting the last three (from logger.info()) in my console and the last two (from logger.warning()) in my file at temp/error.log. This is the expected correct behavior. So I am not getting the error here.

Are you sure you are adding the logger.setLevel(logging.INFO) at the beginning? If you don't, then you will get the same level for both file and console. Do check that and let me know. Hope this helps!

logging setLevel, how it works

It's there for fine-tuning (you can have multiple handlers, and each could have different levels set) — you can safely not set level on the handler, which will cause it to process all messages (a.k.a. NOTSET level), and leave level filtering to the logger.

Logger is also the first to filter the message based on a level — if you set the logger to INFO, and all handlers to DEBUG, you still won't receive DEBUG messages on handlers — they'll be rejected by the logger itself. If you set logger to DEBUG, but all handlers to INFO, you won't receive any DEBUG messages either — because while the logger says "ok, process this", the handlers reject it (DEBUG < INFO).

How to set different levels for different python log handlers

You can set a different logging level for each logging handler but it seems you will have to set the logger's level to the "lowest". In the example below I set the logger to DEBUG, the stream handler to INFO and the TimedRotatingFileHandler to DEBUG. So the file has DEBUG entries and the stream outputs only INFO. You can't direct only DEBUG to one and only INFO to another handler. For that you'll need another logger.

logger = logging.getLogger("mylog")
formatter = logging.Formatter(
    '%(asctime)s | %(name)s |  %(levelname)s: %(message)s')
logger.setLevel(logging.DEBUG)

stream_handler = logging.StreamHandler()
stream_handler.setLevel(logging.INFO)
stream_handler.setFormatter(formatter)

logFilePath = "my.log"
file_handler = logging.handlers.TimedRotatingFileHandler(
    filename=logFilePath, when='midnight', backupCount=30)
file_handler.setFormatter(formatter)
file_handler.setLevel(logging.DEBUG)

logger.addHandler(file_handler)
logger.addHandler(stream_handler)

logger.info("Started");
try:
    x = 14
    y = 0
    z = x / y
except Exception as ex:
    logger.error("Operation failed.")
    logger.debug(
        "Encountered {0} when trying to perform calculation.".format(ex))

logger.info("Ended");

Setting different log levels for different python log handlers

The root logger always has an explicit level set (WARNING by default). Therefore it is not enough to set the level of the handlers - the level of the logger itself should be set to the lowest of the handler's levels, in my case:

logger.setLevel(logging.INFO)

How to specify levels in python logging module?

You could create your own Handler:

logger = logging.getLogger('DBMQ')
logger.setLevel(logging.DEBUG)

class MyStreamHandler(logging.StreamHandler):
    def emit(self, record):
        if record.levelno == self.level:
            super().emit(record)

stream_handler = MyStreamHandler()
stream_handler.setLevel(logging.INFO)

logger.addHandler(stream_handler)

file_handler = logging.FileHandler('./data/file.log')
file_handler.setLevel(logging.WARNING)

logger.addHandler(file_handler)

Logging setLevel is being ignored

As pointed by some users, using:

logging.basicConfig(level=logging.DEBUG, format='%(message)s')

like written in the accepted answer is not a good option because it sets the log level for the root logger, so it may lead to unexpected behaviours (eg. third party libraries may start to log debug messages if you set loglevel=logging.DEBUG)

In my opinion the best solution is to set log level just for your logger, like this:

import logging

logger = logging.getLogger('MyLogger')
handler = logging.StreamHandler()
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
handler.setFormatter(formatter)
logger.addHandler(handler)
logger.setLevel(logging.DEBUG)

Not really intuitive solution, but is necessary if you want to set log level only for 'MyLogger' and leave the root logger untouched.

So, why is logging.basicConfig(level=logging.DEBUG, format='%(message)s') setting the log level globally?

Well, actually it doesn't. As said, it's just changing the configuration of the root logger and, as described in the python documentation:

Loggers should NEVER be instantiated directly, but always through the
module-level function logging.getLogger(name). Multiple calls to
getLogger() with the same name will always return a reference to the
same Logger object.

So, logging.basicConfig is creating a StreamHandler with a default Formatter and adding it to the root logger.

The point is that if any other library is using the "root logger", you're going to set that log level for that library too so it can happen that you start to see debug logs from third party libraries.

This is why I think it's better to create your own logger and set your own formatters and handlers, so you can leave the root logger untouched.

---

Related Topics