Python Log Level with an additional verbosity depth

Question

I would like to extend the existing logging.LEVEL mechanics so that I have the option of switching between different logging levels such as DEBUG, INFO, ERROR etc. but also define a depth for each of the levels.

For example, let's assume that the logging level is set to logging.DEBUG. All of the log.DEBUG() calls will be visible.

log.debug('Limit event has occurred.')

So I get:

[2016-10-08 10:07:29,807] <__main__> {myApp:test_condition_info:93} (DEBUG) Limit event has occurred.

What I am after, is passing an extra depth level to the log.debug() call so that I can control how much of detail is printed in the DEBUG message, not entirely enabling or disabling the DEBUG level but controlling how much information the debug message will carry. So in all cases we see the debug message but in some instances, it is less detailed and on some occasions more information is included.

For example:

log.debug('Limit event has occurred.', verbosity=1)
log.debug('The following user has caused the limit event: %s' % (user), verbosity=3)
log.debug('The following files have been affected: %s' % [list_of_files], verbosity=7)

So when the logging level is set to DEBUG and the global verbosity is set to GLOBAL_VERBOSITY=1 we will get this:

[2016-10-08 10:07:29,807] <__main__> {myApp:test_condition_info:93} (DEBUG) Limit event has occurred.

And if the global verbosity is set to GLOBAL_VERBOSITY=4 we will get this:

[2016-10-08 10:07:29,807] <__main__> {myApp:test_condition_info:93} (DEBUG) Limit event has occurred.
[2016-10-08 10:07:29,807] <__main__> {myApp:test_condition_info:93} (DEBUG) The following user has caused the limit event: xpr

And if the global verbosity is set to GLOBAL_VERBOSITY=9 we will get all of the details:

[2016-10-08 10:07:29,807] <__main__> {myApp:test_condition_info:93} (DEBUG) Limit event has occurred.
[2016-10-08 10:07:29,807] <__main__> {myApp:test_condition_info:93} (DEBUG) The following user has caused the limit event: xpr
[2016-10-08 10:07:29,807] <__main__> {myApp:test_condition_info:93} (DEBUG) The following files have been affected: ['inside.ini', 'render.so']

How should I approach this problem?

Answer 1

Can't you just use the more fine grained logging levels? DEBUG is just a wrapper for level 10. You can use

Logger.log(10, "message")

to log at debug level and then

Logger.log(9, "message")

which won't show up at debug level, but will if you do

Logger.setLevel(9)

If you're dead set on doing it the other way, you should look at 'filters'.

logging with filters

#!/usr/bin/env python
import logging

GLOBAL_VERBOSITY = 1

class LoggingErrorFilter(logging.Filter):
  def filter(self, record):
    if record.__dict__.get("verbosity", 0) > GLOBAL_VERBOSITY:
      print "Log message verbosity is greater than threshold, logging line:{0}".format(record)
      return True
    print "Log message verbosity is lower than threshold, not logging line:{0}".format(record)
    return False

logging.basicConfig(level=logging.DEBUG, filename="test.log")

logger = logging.getLogger()

filter = LoggingErrorFilter()

logger.addFilter(filter)


def main():
    logger.info("Message 1", extra={"verbosity":3})
    logger.info("Message 2", extra={"verbosity":1})


if __name__ == "__main__":
    main()