Python/logging

Common Module Setup

import logging

logger = logging.getLogger(__name__)
logging.basicConfig(level=logging.DEBUG)

logger.info("hello")

Logging

• logging — Logging facility for Python — Python 3 documentation - https://docs.python.org/3/library/logging.html
• Logging HOWTO — Python Dev Version documentation - http://docs.python.org/dev/howto/logging.html
• Logging Cookbook — Python Dev Version documentation - http://docs.python.org/dev/howto/logging-cookbook.html

Setup logger:

import logging
logging.basicConfig(level=logging.DEBUG,format='[%(asctime)s.%(msecs)03d] %(levelname)s %(filename)s(line:%(lineno)d): %(message)s')

Log Levels:

import logging
msg = "i broke"
logging.debug(msg)
logging.info(msg)
logging.warning(msg)   # WARNING:root:i broke
logging.error(msg)     # ERROR:root:i broke
logging.critical(msg)  # CRITICAL:root:i broke

log.setLevel(level)  # debug, info, warn/warning, error, critical
log.setLevel(logging.DEBUG)

A good convention to use when naming loggers is to use a module-level logger, in each module which uses logging, named as follows: [1]

logger = logging.getLogger(__name__)

Simple example: [2]

log_format='%(asctime)s | %(levelname)s | %(message)s'
log_date_format='%Y-%m-%d %H:%M:%S'
logging.basicConfig(format=log_format, datefmt=log_date_format)
log = logging.getLogger(__name__)
log.setLevel(logging.INFO)

log.info('hi')

Formatter function:

def makeFormatter(format_str="", date_format="%Y-%m-%d %H:%M:%S"):
    if not format_str:
        format_str = "%(asctime)s | %(levelname)s | %(filename)s:%(lineno)d:%(funcName)s | %(message)s"
    return logging.Formatter(fmt=format_str, datefmt=date_format)

Medium example:

# Create logger
log_format='%(asctime)s | %(levelname)s | %(message)s'
log_date_format='%Y-%m-%d %H:%M:%S'
log_formatter = logging.Formatter(fmt=log_format, datefmt=log_date_format)
log = logging.getLogger(__name__)
log.setLevel(logging.DEBUG)

# Log to console
ch = logging.StreamHandler()
ch.setLevel(logging.INFO)
ch.setFormatter(log_formatter)
log.addHandler(ch)

# Log to file
fh = logging.FileHandler('my_logger.log')
fh.setLevel(logging.DEBUG)
fh.setFormatter(log_formatter)
log.addHandler(fh)

Log all loggers to file - attach to root logger

import logging

logger = logging.getLogger(__name__)

# Configure Logger
log_format='%(asctime)s | %(name)s | %(levelname)s | %(message)s'
log_date_format='%Y-%m-%d %H:%M:%S'
log_formatter = logging.Formatter(fmt=log_format, datefmt=log_date_format)
logging.basicConfig(level=logging.DEBUG, format=log_format, datefmt=log_date_format)

# Setup Log to File handler, and attach to root logger
root_logger = logging.getLogger()  # Calling getLogger() without a name returns the root logger
fh = logging.FileHandler('logger.txt')
fh.setLevel(logging.DEBUG)
fh.setFormatter(log_formatter)
root_logger.addHandler(fh)

Application Setup (not basic log configuration carries across imported modules):

import logging
def main():
    logging.basicConfig(filename='myapp.log', level=logging.INFO)
    logging.info('Started')
    ...
    logging.info('Finished')

if __name__ == '__main__':
    main()

Log multiple lines:

for line in output.splitlines():
    log.debug(line)

Set log level: (warning is default)

logging.basicConfig(level=logging.DEBUG)

Set log level from string value: [3]

# assuming loglevel is bound to the string value obtained from the
# command line argument. Convert to upper case to allow the user to
# specify --log=DEBUG or --log=debug
numeric_level = getattr(logging, loglevel.upper(), None)
if not isinstance(numeric_level, int):
    raise ValueError('Invalid log level: %s' % loglevel)
logging.basicConfig(level=numeric_level, ...)

Log to file:

logging.basicConfig(filename='example.log',level=logging.DEBUG)
logging.basicConfig(filename='example.log', filemode='w', level=logging.DEBUG)  # do not append

Format output: (once set, can't be changed?)

# WARNING:MESSAGE
logging.basicConfig(format='%(levelname)s:%(message)s', level=logging.DEBUG)

# 05/23/2011 12:50:02 PM MESSAGE
logging.basicConfig(format='%(asctime)s %(message)s', datefmt='%m/%d/%Y %I:%M:%S %p')

# 05/23/2011 12:55:28 PM : WARNING : MESSAGE
logging.basicConfig(format='%(asctime)s : %(levelname)s : %(message)s', datefmt='%m/%d/%Y %I:%M:%S %p')

# 2011-05-23 13:05:30 : WARNING : MESSAGE
logging.basicConfig(format='%(asctime)s : %(levelname)s : %(message)s', datefmt='%Y-%m-%d %H:%M:%S')

# 2011-05-23 13:05:30 | WARNING | FILE:FUNC | MESSAGE
logging.basicConfig(format='%(asctime)s | %(levelname)s | %(filename)s:%(funcName)s | %(message)s', datefmt='%Y-%m-%d %H:%M:%S')

Log record attributes - http://docs.python.org/library/logging.html#logrecord-attributes

Format Example:

FORMAT = '%(asctime)-15s %(clientip)s %(user)-8s %(message)s'  # doesn't work!
logging.basicConfig(format=FORMAT)
d = { 'clientip' : '192.168.0.1', 'user' : 'fbloggs' }
logger = logging.getLogger('tcpserver')
logger.warning('Protocol problem: %s', 'connection reset', extra=d)

import logging

# create logger with 'spam_application'
logger = logging.getLogger('spam_application')
logger.setLevel(logging.DEBUG)

# create file handler which logs even debug messages
fh = logging.FileHandler('spam.log')
fh.setLevel(logging.DEBUG)

# create console handler with a higher log level
ch = logging.StreamHandler()
ch.setLevel(logging.ERROR)

# create formatter and add it to the handlers
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
fh.setFormatter(formatter)
ch.setFormatter(formatter)

# add the handlers to the logger
logger.addHandler(fh)
logger.addHandler(ch)

logger.info('Message to loggers and handlers')