To debug your program, you may be tempted to pepper your source code with
print() calls to display the values of variables as your program runs. It's quick and easy to do this, but the problem is that once you see the values in the variables, that'll give you ideas for more places to put
print() calls, then you run the program again to learn where to put other
print() calls. The "quick" solution of adding
print() eats up a lot of time as you get sucked into this add
To become a better programmer, you should learn how to use the debugger and Python's
logging module. Nina Zakharenko's PyCon US 2020 talk, "Goodbye Print, Hello Debugger" is an excellent introduction to the debugger. This blog post covers Python's built-in
logging is better than printing because:
- You can save the log to a text file instead of just on the screen where you could easily lose it.
- It's easy to put a timestamp in each message, which is very handy.
- You can have different levels of urgency for messages, and filter out less urgent messages.
- When you want to later find log messages in or remove log messages from your source code, you won't get them confused with the real
print()calls used for program output.
- If you just print to a log file, it's easy to leave the log function calls in and just ignore them when you don't need them. (You don't have to constantly pull out and add in
logging Code to Copy and Paste
To print log messages to the screen, copy and paste this code:
import logging logging.basicConfig(level=logging.DEBUG, format='%(asctime)s - %(levelname)s - %(message)s') logging.debug('This log message appears on the screen.')
To write log messages to a file, you can copy and paste this code (the only difference is in bold):
import logging logging.basicConfig(filename='log_filename.txt', level=logging.DEBUG, format='%(asctime)s - %(levelname)s - %(message)s') logging.debug('This log message appears in log_filename.txt.')
Later runs of the program will append to the end of the log file, rather than overwrite the file.
To log messages to a file AND printed to the screen, copy and paste the following:
import logging logger = logging.getLogger() logger.setLevel(logging.DEBUG) formatter = logging.Formatter('%(asctime)s - %(levelname)s - %(message)s') fh = logging.FileHandler('log_filename.txt') fh.setLevel(logging.DEBUG) fh.setFormatter(formatter) logger.addHandler(fh) sh = logging.StreamHandler() sh.setLevel(logging.DEBUG) sh.setFormatter(formatter) logger.addHandler(sh) logger.debug('This log message appears on the screen and in log_filename.txt.')
logging.Formatter object determines how the log messages are displayed. The handlers specify the destination for the log message:
FileHandler send them to a text file and
StreamHandler sends them to the stderr stream which often means the screen.
Make sure that the
logger variable is global, so that you can use it in functions. (You don't need the "
global logger" at the top of the function, because the
logger variable is only read, not modified.)
The different levels of logging, from highest urgency to lowest urgency, are:
- CRITICAL - For errors that cannot be recovered from or cause a system to fail.
- ERROR - For preventable errors that happen.
- WARNING - For situations where nothing has gone wrong yet, but could potentially cause errors in the future.
- INFO - For general informative messages about something that happened in the program. (Examples: A file being read, an email being sent, etc.)
- DEBUG - For low-level details that concern the source code. (Examples: A function being called, the value in a particular variable, etc.)
setLevel() call sets the minimum log level of messages it actually logs. So if you
fh.setLevel(logging.ERROR), then WARNING, INFO, and DEBUG log messages will not be written to the log file (since
fh is the log handler for the log file, as opposed to
ch which is the handler for the console screen.)
To write a log message in one of these five levels, use the following functions:
logger.critical('The system encountered an unknown error and cannot continue.')
logger.error('No response from server.')
logger.warning('Protocol problem. Connection was reset.')
logger.info('System started at ' + str(datetime.datetime.now()))
logger.debug('accountID = ' + str(accountID))
There's plenty more you can do, but this all you need to know to never again use
print() calls to do your debugging work.
Also, the pprint.pprint() function is great for "pretty printing" dictionaries and lists that have nested dictionaries and lists in them. The pprint.pformat() function returns the string of this content, rather than printing it to the screen.
One final tip: You can use the
tail -f logfile.txt command to show a file as it is being written to. The -f stands for "follow". Just leave a terminal/console window open with this command running, and new text in the log file will appear as it is written. This way, you don't have to keep opening/reloading a text editor to view the latest text in the log file.
The tail command comes on Mac OS X and Linux OSes. On Windows, you can download the Cygwin project to get the tail command.
(But also: you can still use
print() for quick debugging if you really want to. Just remember that short cuts often make longer trips.)
UPDATED 2021/12/17: Rewrote large parts of the blog post. Added link to Nina's PyCon talk.