Logging in Python

Ashutosh Kumar
5 min readOct 9, 2019

--

Unless you have pushed a data science model into production, there is high chance you have not logged anything going on in your model framework. Preparing proper logs is an essential part of good software engineering, and if you are preparing any model to be deployed to production, it is imperative you ensure proper logging is done.

Why is logging needed: For multiple reasons — being able to look into detail in case your model breaks down or its is not performing as expected, and also to provide regulatory compliance (needed in some cases) where you need to track every data that goes in and out of your model. The logs provide you a trail of bread crumbs that can be used to check if something goes wrong, the cause of the problem can be determined

Python provides a package name ‘logging’ which is more than enough to log on all your activities in a disk or output to a console. The TimedRotatingFileHandler ensures that the log files do not become enormous, and you restrict the log recording with logging config files.

Levels of Logging (System assigned numeric values in parentheses)

DEBUG(10), INFO(20), WARNING(30), ERROR(40), CRITICAL(50)

  • Debug : These are used to give Detailed information, typically of interest only when diagnosing problems.
  • Info: These are used to confirm that things are working as expected
  • Warning: These are used as an indication that something unexpected happened, or indicative of some problem in the near future
  • Error: This tells that due to a more serious problem, the software has not been able to perform some function
  • Critical: This tells serious error, indicating that the program itself may be unable to continue running

Logger Objects

There are several logger objects offered by the module itself.

  • Logger.info(msg): This will log a message with level INFO on this logger.
  • Logger.warning(msg): This will log a message with level WARNING on this logger.
  • Logger.error(msg): This will log a message with level ERROR on this logger.
  • Logger.critical(msg): This will log a message with level CRITICAL on this logger.
  • Logger.log(lvl,msg): This will Logs a message with integer level lvl on this logger.
  • Logger.exception(msg): This will log a message with level ERROR on this logger.
  • Logger.setLevel(lvl): This function sets the threshold of this logger to lvl. This means that all the messages below this level will be ignored.
  • Logger.addFilter(filt): This adds a specific filter filt to the to this logger.
  • Logger.removeFilter(filt): This removes a specific filter filt to the to this logger.
  • Logger.filter(record): This method applies the logger’s filter to the record provided and returns True if record is to be processed. Else, it will return False.
  • Logger.addHandler(hdlr): This adds a specific handler hdlr to the to this logger.
  • Logger.removeHandler(hdlr): This removes a specific handler hdlr to the to this logger.
  • Logger.hasHandlers(): This checks if the logger has any handler configured or not.

Logging Classes

The most commonly used classes defined in the logging module are the following:

  • Logger: This is the class whose objects will be used in the application code directly to call the functions.
  • LogRecord: Loggers automatically create LogRecord objects that have all the information related to the event being logged, like the name of the logger, the function, the line number, the message, and more.
  • Handler: Handlers send the LogRecord to the required output destination, like the console or a file. Handler is a base for subclasses like StreamHandler, FileHandler, SMTPHandler, HTTPHandler, and more. These subclasses send the logging outputs to corresponding destinations, like sys.stdout or a disk file.
  • Formatter: This is where you specify the format of the output by specifying a string format that lists out the attributes that the output should contain.

Coding the Logger

Logging without setting any level — Default level is WARNING — anything below this level (DEBUG, INFO) will be ignored

import logginglogging.debug('This is a debug message')
logging.info('This is an info message')
logging.warning('This is a warning message')
logging.error('This is an error message')
logging.critical('This is a critical message')
"""
Output:
WARNING:root:This is a warning message
ERROR:root:This is an error message
CRITICAL:root:This is a critical message
"""

See the default level of logging

logger = logging.getLogger(__name__)
# Out: <Logger __main__ (WARNING)>

Set the level of logging

#Creating an object 
logger=logging.getLogger()

#Setting the threshold of logger to DEBUG
logger.setLevel(logging.DEBUG)
logger.debug("This is a Debug Message")
logger.info("This is an Information Message")
logger.warning("This is a Warning Message")
logger.error("This is an Error Message")
logger.critical("This is a Critical Message")
"""
Output (This is the Default Format of writing logs - can be configured):
DEBUG:root:This is a Debug Message
INFO:root:This is an Information Message
WARNING:root:This is a Warning Message
ERROR:root:This is an Error Message
CRITICAL:root:This is a Critical Message
"""

Logging to a File

PATH = "/your_filepath_here/"#Create and configure logger 
logging.basicConfig(filename="testlog.log",
format='%(asctime)s %(message)s',
filemode='w')

Point to Note:

It should be noted that calling basicConfig() to configure the root logger works only if the root logger has not been configured before. Basically, this function can only be called once.

Setting the Format

import logginglogging.basicConfig(format='%(process)d-%(levelname)s-%(message)s')
logging.warning('This is a Warning')
"""
Output:
10290-WARNING-This is a Warning
"""
logging.basicConfig(format='%(asctime)s - %(message)s', datefmt='%d-%b-%y %H:%M:%S')
logging.warning('Admin logged out')
# Output:
# 2018-07-11 20:12:06,288 - Admin logged in

Remember — basic Config can be called only one. If you are testing this core and the format is not as per expectations, close the session/code and restart

Capturing stack traces

Log the complete error traceback exc_info=True must be present

import loggingx = 1
y = 0
try:
z = x/y
except Exception as e:
logging.error("Exception occurred", exc_info=True)

Using Logging.exception() method, which logs a message with level ERROR and adds exception information to the message. To put it more simply, calling logging.exception() is like calling logging.error(exc_info=True)

x = 1
y = 0
try:
z = x/y
except Exception as e:
logging.exception("Exception occurred")

Console Output and File Output with Different Formats

StreamHandler and FileHandlers

import logging# Create a custom logger
logger = logging.getLogger(__name__)
# Create handlers
consoleHandler = logging.StreamHandler()
fileHandler = logging.FileHandler(PATH+'logfile.log')
consoleHandler.setLevel(logging.WARNING)
fileHandler.setLevel(logging.ERROR)
# Create formatters and add it to handlers
consoleFormat = logging.Formatter('%(name)s - %(levelname)s - %(message)s')
fileFormat = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
consoleHandler.setFormatter(consoleFormat)
fileHandler.setFormatter(fileFormat)
# Add handlers to the logger
logger.addHandler(consoleHandler)
logger.addHandler(fileHandler)
logger.warning('Logging Warning Message')
logger.error('Logging Error Message')
"""
Console Output:
__main__ - WARNING - Logging Warning Message
__main__ - ERROR - Logging Error Message

File Output:
2019-10-09 13:54:41,107 - __main__ - ERROR - Logging Error Message
"""

Why Different Outputs? The level of logging set on File Handler is ERROR — so all the logging messages below this level (including Warning) will be ignored For StreamHandler Object, the level of logging set is WARNING, so this will print both the WARNING and ERROR messages

Sources:

--

--

Ashutosh Kumar
Ashutosh Kumar

Written by Ashutosh Kumar

Data Science @ Epsilon ; interested in technology, data , algorithms and blockchain. Reach out to me at ashu.iitkgp@gmail.com