Logging is one of the powerful features of python that is rarely used by beginners because it looks difficult from the outset. Most of us use print debugging: the print() function is used to output debug messages like here, or entered test function. Why then, do you bother to learn a new module? Consider a simple python script with a recursive function:
def basicRecursiveFunction(n: int):
if n==0:
# base case handling
print("finished recursive calls")
return
else if n>0:
print("some info about the current function call")
# aim of function
basicRecursiveFunction(n-1)
basicRecursiveFunction(10)
When we are testing the above code, we might want the info part in both cases to run, to help us understand whether the recursive function is working (whatever that may be). Once we have ensured that the function is running, we will go and either delete or comment out the two print calls, viz:
# print("finished recursive calls")
# ....
# print("some info about the current function call")
What if the code is a hundred lines long, and includes required print calls alongside the debug print calls?
That is where logging comes in!
Logging allows the developer to generate different types of log messages, save program logs to files and so on, which would be difficult to implement manually with the open() function. Also, it allows us to redirect logs, selectively display logs, and much more...
Logging levels
There are five levels of logging in Python:
logging.debug()
logging.warning()
logging.error()
logging.critical()
The lowest severity level is debug(), and the highest severity level is critical(). The basic idea is that of priorities. When writing complex programs, we run whichever log function best suits the message (i.e priority). Later on, we can disable any or some log outputs directly (explained further down), in the cascade fashion viz disabling logging for error() level means all log messages except those with higher priority are disabled. For example, disabling the logging.CRITICAL level makes all log messages transparent i.e none of the log messages with lower priority are displayed. On the contrary, disabling logging.WARNING will not block the error() and critical() logs.
One can also change what log messages are shown by modifying the call to basicConfig function.
Basic Logging
Using logging as a replacement to print() for debug messages
The easiest way to use logging relies on a simple one-line setup and then can be used at any point for different types of error messages. The following snippet at the top of the file or interpreter sets up your script for logging.
import logging
logging.basicConfig(
level=logging.DEBUG,
format="Time: %(asctime)s ; %(levelname)s ; %(funcName)s-\n %(message)s\n"
)
The format specifies the format of the log output. We can chop and change the message format by including any of the LogRecord attributes, listed here. These include funcName, levelname, levelno, lineno, message, name, process, processName and so on.
The real value of logging can be explained with the following script(which has an error!):
#!python3
# simple program to use logging in a fibonacci function
import logging
logging.basicConfig(
level=logging.DEBUG,
format="Time: %(asctime)s ; Level:%(levelname)s ; Function:%(funcName)s\n %(message)s\n"
)
def fibonacci1(n = 0):
a,b = 0,0
logging.info("Beginning the fibonacci function for n = "+ str(n))
logging.info("a = "+ str(a) + " and b = "+str(b))
i = 1
if n > 75:
logging.warning("The number is too big:")
return -1
while i < n:
logging.info("currently (a,b) is ( "+str(a)+" ," + str(b)+" ) , a+b = "+ str(a+b))
a,b = b,a+b
i += 1
logging.debug("end of fibonacci function, output = " + str(a))
return a
# calling the fibonacci1 function
print("fibonacci of 6 is "+ str(fibonacci1(6)))
The above code generates the output:
Wait! The 6th Fibonacci term is 5: if the function is giving 0, it means there is an error! What is the error? Voila! Checking the log messages, I find that initially, I set both a and b to 0, which meant that the Fibonacci series never got generated!
Once I've found and fixed the error (replace b = 0 by b=1), and my function is returning the correct value for the Fibonacci term, I want to remove all the debug messages. A conventional print() use-case would require traversal through the function to remove the extra output statements: with logging, once our need for logging statements is done, we can directly disable all the log messages by adding this snippet somewhere at the top of the script:
logging.disable(logging.CRITICAL)
As the CRITICAL level has top priority, adding the above line disables all log messages BELOW the disable() call (which is why you should add the above line at the very top if you want to disable ALL error messages.)
Disabling logging at the logging.CRITICAL level is not recommended, as even the useful error messages generated when critical, breaking states occur in programs will not be displayed. A more balanced approach would be to disable logging from the info() and debug() functions, and keep warning(), error() and critical() log messages active. Change the logging.basicConfig() call at the top of the program to the following:
import logging
logging.basicConfig(
level=logging.WARNING,
format="Time: %(asctime)s ; %(levelname)s ; %(funcName)s-\n %(message)s\n"
)
The above disables all log messages, except the number is too big message that is generated when the fibonacci1 function is called with an argument greater than 75. This ensures that while our corrected program runs for all cases, it displays a warning when our input condition cannot generate the correct output. Thus, when I use the function in a large program, the above error will provide a warning to ensure that the input to the function is less than 76.
Logging into a file
When working with complex programs, it is tedious to read the logs off the console. The logging module makes log redirection to files very simple. Just add another attribute to the logging.basicConfig() call in the program:
logging.basicConfig(
level=logging.DEBUG,
filename="Programlog.log",
format="Time: %(asctime)s ; Level:%(levelname)s ; Function:%(funcName)s\n %(message)s\n"
)
This saves your program log inside the working directory from where the script is executed( by default, the current working directory in the command line from where you say python script.py, or from the root of the workspace (if you are using a code editor like VSCode.)
Logging handlers
You can route logs to different locations using different types of log handlers; these include StreamHandler, SMTPHandler, FileHandler etc. By default, the logging module's StreamHandler logs messages to sys.stderr.
To use handlers, one needs to create an instance of the required handler and add it to a logger. For example, if I wanted to send my errors in the buggy Fibonacci code to a log file, I'd add the following after logging.basicConfig():
# logging.basicConfig(stuff)
logFileHandler = logging.FileHandler('fibonacci.log')
logFileHandler.setLevel(logging.DEBUG)
logging.getLogger('').addHandler(logFileHandler)
# fibonacci definition and call
Adding the above snippet to the broken Fibonacci code generates the following :
Running the same code again appends the new logs to the end of the fibonacci.log file, which allows the programmer to perform some low-level testing for different conditions; reading the logs from both successful and unsuccessful program executions can help you locate and fix your code faster, rather than having to search for error messages on the console.
Conclusion
The logging module levels up your debugging game and can be a powerful weapon in your arsenal in the war against bugs! And all this is just the tip of the iceberg! Lots more features, like asynchronous logging, filters, contextual logging, rotating log files etc make logging a very useful module for any budding pythonista!!!