worked examples of argparse and python logging

.gitignore

logs/

README.md

argparse and logging sample code

args.py

#! /usr/bin/env python
"""Sample Code Demonstrating argparse and logging

Demonstrates appropriate logging techniques for a trivial command line program
that supports a variety of "verbosity" flags.
"""

import argparse
import logging
import logging.handlers
import os
import sys
import six

logger = logging.getLogger('owl.args.example')
logger.setLevel(logging.DEBUG)

# always write everything to the rotating log files
if not os.path.exists('logs'): os.mkdir('logs')
log_file_handler = logging.handlers.TimedRotatingFileHandler('logs/args.log', when='M', interval=2)
log_file_handler.setFormatter( logging.Formatter('%(asctime)s [%(levelname)s](%(name)s:%(funcName)s:%(lineno)d): %(message)s') )
log_file_handler.setLevel(logging.DEBUG)
logger.addHandler(log_file_handler)

# also log to the console at a level determined by the --verbose flag
console_handler = logging.StreamHandler() # sys.stderr
console_handler.setLevel(logging.CRITICAL) # set later by set_log_level_from_verbose() in interactive sessions
console_handler.setFormatter( logging.Formatter('[%(levelname)s](%(name)s): %(message)s') )
logger.addHandler(console_handler)

parser = argparse.ArgumentParser(
    description="performs a variety of operations on a file.", 
    epilog="pretty neat, huh?", 
    fromfile_prefix_chars='@',
)
parser.add_argument('command', nargs="?", default="count", help="command to execute", choices=['count', 'head', 'tail'])
parser.add_argument('file', help="input filename", metavar='FILE')

parser.add_argument('-V', '--version', action="version", version="%(prog)s 0.17.2")
parser.add_argument('-m', '--maximum', type=int, default=1024**2, help="maximum file length to read", metavar='MAX')
parser.add_argument('-v', '--verbose', action="count", help="verbose level... repeat up to three times.")
parser.add_argument('-%', '--modulo', type=int, help="returns the length modulo this integer")
parser.add_argument('-g', '--guess', action="store_true", default=False, help="return a random guess instead of bothering to read the file. Because \"lazy\" programming is GOOD programming.")


def handle_count_command(args):
    logger.warning("handling count command...")
    if args.guess:
        import random
        logger.warn('taking a random guess!')
        print(random.randint(0,args.maximum))
        return

    filename = args.file
    try:
        with open(filename, 'r') as input_file:
            logger.info("opened file: {0}".format(filename))
            logger.debug("file opened in read mode")
            file_length = len(input_file.read(args.maximum))

            if args.modulo:
                logger.debug('computing the length modulo {:,} operator'.format(args.modulo))
                file_length = file_length % args.modulo

            logger.debug("read all data from file")
            print('{filename}: {file_length}'.format( **locals() ))
        logger.debug("closed file")
    except IOError:
        logger.error("file not found: {}".format(filename))
        logger.critical("unable to count file!")
    except Exception as e:
        logger.critical("unknown error while attempting to read file length", exc_info=True)
        six.reraise(*sys.exc_info())

def handle_head_command(args):
    logger.warning("handling head command...")

    filename = args.file
    try:
        with open(filename, 'rb') as input_file:
            logger.debug("file opened in binary read mode")
            print(input_file.read(256))
    except IOError:
        logger.error("file not found: {}".format(filename))
        logger.critical("unable to head file!")


def set_log_level_from_verbose(args):

    if not args.verbose:
        console_handler.setLevel('ERROR')
    elif args.verbose == 1:
        console_handler.setLevel('WARNING')
    elif args.verbose == 2:
        console_handler.setLevel('INFO')
    elif args.verbose >= 3:
        console_handler.setLevel('DEBUG')
    else:
        logger.critical("UNEXPLAINED NEGATIVE COUNT!")


if __name__ == '__main__':
    args = parser.parse_args()
    set_log_level_from_verbose(args)
    if args.command == 'count':
        handle_count_command(args)
    elif args.command == 'head':
        handle_head_command(args)
    else:
        logger.error("Unknown command: {}".format(args.command))

args2.py

#! /usr/bin/env python
"""Sample code diving deeper into argparse "subparsers" feature.
"""

import argparse
import logging
import logging.handlers
import os

logger = logging.getLogger('owl.args.example')
logger.setLevel(logging.DEBUG)

# always write everything to the rotating log files
if not os.path.exists('logs'): os.mkdir('logs')
log_file_handler = logging.handlers.TimedRotatingFileHandler('logs/args.log', when='M', interval=2)
log_file_handler.setFormatter( logging.Formatter('%(asctime)s [%(levelname)s](%(name)s:%(funcName)s:%(lineno)d): %(message)s') )
log_file_handler.setLevel(logging.DEBUG)
logger.addHandler(log_file_handler)

# also log to the console at a level determined by the --verbose flag
console_handler = logging.StreamHandler() # sys.stderr
console_handler.setLevel(logging.CRITICAL) # set later by set_log_level_from_verbose() in interactive sessions
console_handler.setFormatter( logging.Formatter('[%(levelname)s](%(name)s): %(message)s') )
logger.addHandler(console_handler)

parser = argparse.ArgumentParser(
    description="performs a variety of operations on a file.", 
    epilog="pretty neat, huh?", 
    fromfile_prefix_chars='@',
)
parser.add_argument('-V', '--version', action="version", version="%(prog)s 2.0")
parser.add_argument('-v', '--verbose', action="count", help="verbose level... repeat up to three times.")

commands = parser.add_subparsers(dest="command", help="sub-commands")
count_parser = commands.add_parser("count", help="count the number of characters in a file")
count_parser.add_argument('file', help="input filename", metavar='FILE')
count_parser.add_argument('-m', '--maximum', type=int, default=1024**2, help="maximum file length to read", metavar='MAX')
count_parser.add_argument('-%', '--modulo', type=int, help="returns the length modulo this integer")
count_parser.add_argument('-g', '--guess', action="store_true", default=False, help="return a random guess instead of bothering to read the file. Because \"lazy\" programming is GOOD programming.")

head_parser = commands.add_parser("head", help="show the first 256 characters of a file")
head_parser.add_argument('files', nargs="+", help="input filename", metavar='FILE')


def handle_count_command(args):
    logger.warning("handling count command...")
    if args.guess:
        import random
        logger.warn('taking a random guess!')
        print(random.randint(0,args.maximum))
        return

    filename = args.file
    try:
        with open(filename, 'r') as input_file:
            logger.info("opened file: {0}".format(filename))
            logger.debug("file opened in read mode")
            file_length = len(input_file.read(args.maximum))

            if args.modulo:
                logger.debug('computing the length modulo {:,} operator'.format(args.modulo))
                file_length = file_length % args.modulo

            logger.debug("read all data from file")
            print('{filename}: {file_length}'.format( **locals() ))
        logger.debug("closed file")
    except IOError:
        logger.error("file not found: {}".format(filename))
        logger.critical("unable to count file!")
    except Exception as e:
        logger.critical("unknown error while attempting to read file length", exc_info=True)

def handle_head_command(args):
    logger.warning("handling head command...")

    for filename in args.files:
        try:
            print(filename, ':')
            with open(filename, 'rb') as input_file:
                logger.debug("file opened in binary read mode")
                print(input_file.read(256))
            print()
            logger.info("successfully finished heading file {}".format(filename))
        except IOError:
            logger.error("file not found: {}".format(filename))
            logger.critical("unable to head file!")


def set_log_level_from_verbose(args):

    if not args.verbose:
        console_handler.setLevel('ERROR')
    elif args.verbose == 1:
        console_handler.setLevel('WARNING')
    elif args.verbose == 2:
        console_handler.setLevel('INFO')
    elif args.verbose >= 3:
        console_handler.setLevel('DEBUG')
    else:
        logger.critical("UNEXPLAINED NEGATIVE COUNT!")


if __name__ == '__main__':
    args = parser.parse_args()
    set_log_level_from_verbose(args)
    if args.command == 'count':
        handle_count_command(args)
    elif args.command == 'head':
        handle_head_command(args)
    else:
        logger.error("Unknown command: {}".format(args.command))