Logging in Python
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, its 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 are restrict the log recording with logging config files.
Levels of Logging (System assigned numeric values in parantheses)
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 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
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.
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 logging logging.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 logging logging.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 logging x = 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 Handeler 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