Logging in Python – with function names, line numbers, command line -v -d and aliases v(), d()

Logging is tells you what’s going on when your run and often avoids useless comments. Log messages give you a real time feeling what’s happening in the program. And your advanced users might want to run ‘supercommand –debug’, too.
This short sample program shows common logging tasks that were not prominent in tutorials at the time of writing: showing function names and line numbers, setting log level on the command line and using short aliases for the commands.
Following this tutorial requires fluency in Python.

Result

When you are done, this is what your program will do

$ ./foo.py --verbose
main():31: This is a verbose message INFO

Show Function Name and Line Number

You can set the output format with

fmt="%(funcName)s():%(lineno)i: %(message)s %(levelname)s"
logging.basicConfig(level=args.log_level, format=fmt)

You must do the basicConfig before printing anything to logs.
To print line numbers and function names, you must call functions (e.g. logging.info) directly. They won’t work if you write a wrapper function. So we create the short aliases when importing

from logging import info as v
from logging import debug as d

Now you can use the shorthands for the functions

v("About to start fobarizing the baz...")

Setting Logging Level with Command Line Parameters

You are probably used to setting the logging level with -v, –verbose or –debug. You can set the logging level this way with argparse.
Logging levels (logging.INFO, logging.DEBUG) are integers. So we can just change the value of one int in argparse. Remember to call logging.basicConfig() before you print anything to logs.

 parser.add_argument("-v", "--verbose",
      action="store_const", dest="log_level",
      const=logging.INFO, default=logging.WARNING)
 parser.add_argument("-d", "--debug",
      action="store_const", dest="log_level",
      const=logging.DEBUG)
 args = parser.parse_args()
 logging.basicConfig(level=args.log_level)

Logging will make your life easy. Simply use the correct logging level (verbose, debug) and explain what’s going on. Your advanced user will thank you, you will thank you.

Sample Program

The sample program below (loggingtero.py) is free to copy under the MIT license or the Clarified BSD license. You can choose one of those licenses.

#!/usr/bin/python3
# loggingtero.py
"""Logging with aliases d(), v(), log level -v -d and printed function names.
Printout shows function name and line number, e.g.
 58:main():Failed to fobarize baz, duffing blizes.
Copyright 2015 Tero Karvinen http://TeroKarvinen.com
"""
import logging
from logging import info as v
from logging import debug as d
from logging import error, warning
import argparse
def parseArgs():
 parser = argparse.ArgumentParser(description=__doc__)
 parser.add_argument("-v", "--verbose",
 action="store_const", dest="log_level",
 const=logging.INFO, default=logging.WARNING)
 parser.add_argument("-d", "--debug",
 action="store_const", dest="log_level",
 const=logging.DEBUG)
 return parser.parse_args()
def main():
 args=parseArgs()
 logging.basicConfig(level=args.log_level, format="%(funcName)s():%(lineno)i: %(message)s %(levelname)s")
 print("Use print() to always show lines. For example, normal program output. ")
 v("Verbose messages explain normal functioning. v() aka logging.info()")
 d("Debug messages show technical details of the program. d() aka logging.debug().")
 warning("Warnings are for problems that still allow the program to run. logging.warning().")
 error("Errors mean a failed operation. logging.error(). Also consider sys.exit('Fobarization failed.') or raise().")
if __name__ == "__main__":
 main()