Logging refers to tracking events that occur in a program, so that we can trace or understand its behavior. Python provides ‘logging’ module that makes logging easily implementable. We will begin this series by looking at how to implement logging with a simple example in this post.
Clone demo from github
Python logging module classifies the logs into different levels, which are listed below in the order of their severity, with ‘critical’ being the most severe and ‘debug’ being the least.
When we write our python code, we can log a message with either of the above levels.
Logging module provides multiple functions and inbuilt variables that makes life a lot easier. In this post we will look at one of the functions, “logging.basicConfig”. Let’s look at the below code to understand how it works.
#!/usr/bin/python import logging # set log file name, log level and format of log entry, using logging.basicConfig() function. logging.basicConfig(filename='application.log', level=logging.WARN, format='%(asctime)s - %(levelname)s - %(message)s') # make sample log entries logging.debug(' this is a debug message') logging.info('this is an info message') logging.warn('this is a warn message') logging.error('this is an error message') logging.critical('this is a critical message')
Looking at Line #5 of the above python snippet, we can see that the logging.basicConfig() function accepts a ‘filename’ parameter that tells it to write logs to a file named “application.log”.
The ‘level’ parameter accepts the maximum severity level to log. For example, if log level is set to logging.WARN. then only ‘critical’, ‘error’ and ‘warn’ level entries are logged. If log level is set to ‘debug’ then all the levels are logged, since debug is the least severe log level.
The ‘format’ parameter is another interesting and convenient parameter, that allows us to define the format of how the entry should be logged in the log file. We can make use of the plenty of inbuilt variables to make our log entries informative. For instance, %(asctime)s is an inbuilt variable that provides the time stamp when the log was made, %(levelname)s provides the log level itself such as ‘debug’ or ‘warn etc, %(message)s provides the actual message we logged. There is plenty more such as, %(clientip)s, %(user) etc, which tells the ip address and the user respectively, that caused this log entry. A complete list can be found somewhere on the official documentation for the Python Logging Module.
Now, when the above code snippet is run, a log file ‘application.log’ is created with the below content.
[admin@unixutils py]# cat application.log 2019-01-06 15:28:44,774 - WARNING - warn message 2019-01-06 15:28:44,774 - ERROR - error message 2019-01-06 15:28:44,774 - CRITICAL - critical message [admin@unixutils py]#
Note that, since the log level was set to ‘logging.WARN’, only log entries of severity ‘warn’ or above has been recorded. Had we set the level to ‘logging.DEBUG’, all entries would have been logged to the file.
Now it is up to us to make the log entries more meaningful. For instance, lets take the following objectives.
- record the name, age and application status of an employee
- If the age of the employee is more than 55, then log a warning.
- if the ‘application_status’ of the employee is read as ‘passed’ then record “info” log level, with a message.
- if the ‘application_status’ of the employee is read as ‘failed’ then record “error” log level, with a message.
- If the application status is anything but ‘passed’ or ‘failed’, then record “critical” with a message “unknown application status”
#!/usr/bin/python import logging import sys logging.basicConfig(filename='application.log', level=logging.INFO, format='%(asctime)s - %(levelname)s - %(message)s') employee_name = sys.argv employee_age = int(sys.argv) application_status = sys.argv enrollment_list =  if application_status == "failed": print "Enrollment failed since application status is failed" logging.error('Enrollment failed for: %s', employee_name) logging.error('Enrollment failed since application status is 'failed') elif employee_age > 55 and application_status == 'passed': enrollment_list.append(employee_name+':'+str(employee_age)+':'+application_status) logging.warn('Enrollment successful for: %s', employee_name) logging.warn('age is above threshold') elif employee_age < 55 and application_status == 'passed': enrollment_list.append(employee_name+':'+str(employee_age)+':'+application_status) logging.info('Enrollment successful for: %s', employee_name) else: print "Critical application error, unknown application status" logging.critical('Enrollment failed for: %s', employee_name) logging.critical('Critical application error, unknown application status: %s', application_status) print("printing details:") print(enrollment_list)
The above code snippet accepts name, age and application status as arguments and appends it to a list called enrollment_list, only when our objectives are satisfied. The application.log is created as in the below output.
[admin@unixutils py]# ./enroll.py vijay 30 passed Details: ['vijay:30:passed'] [admin@unixutils py]# ./logging_basics.py harry 56 passed Details: ['harry:56:passed'] [admin@unixutils py]# ./logging_basics juju 50 failed Enrollment failed since application status is failed Details:  [admin@unixutils py]# ./logging_basics kiki 56 xyz Critical application error, unknown application status Details:  [admin@unixutils py]# cat application.log 2019-01-06 17:04:03,912 - INFO - Enrollment successful for: vijay 2019-01-06 17:04:19,937 - WARNING - Enrollment successful for: harry 2019-01-06 17:04:19,938 - WARNING - age is above threshold 2019-01-06 17:05:16,255 - ERROR - Enrollment failed for: juju 2019-01-06 17:05:16,256 - ERROR - Enrollment failed since application status is 'failed' 2019-01-06 17:05:31,840 - CRITICAL - Enrollment failed for: kiki 2019-01-06 17:05:31,841 - CRITICAL - Critical application error, unknown application status [admin@unixutils py]#
In this post, we explored into the basics of logging in python. We will look further into advanced logging concepts such as capturing stack traces and handlers in the future posts.