Python Logging

The process of storing complete application flow and exception information to the file is called as python logging.

The process of tracking an event that happens when some software runs; this can be done by adding a logging call to the code to indicate that some events have occurred.

The main advantage of Python Logging are :

  • We can use python log file while performing debugging
  • By using log files, we can generate utilization reports.
Python provides an in-built Module Logging to implement Logging

The Logging provides a set of convenience functions for simple logging usage, the best set of everyday tasks and the best tool to use for it are as below

Task You want to Perform The Best Tool for the Task
Display console output for ordinary usage of a command-line script or program Print()
Report events that occur during normal operation of a program logging.info()
Issue a warning regarding a particular Runtime event warnings.warn() in library code if the issue is avoidable and the client application should be modified to eliminate the warning
Report an error regarding a particular runtime event Raise an Exception
Report suppression of an error without raising an exception logging.error(), logging.exception(), logging.criticsl() as appreciated for the specific error and application domain.

The logging functions are named after the severity of the events they are used to track. The standard functions and their applicability are described below

CRITICAL ==>Represents a serious problem; maybe the program itself is unable to run, which needs an high attention.

ERROR==>Due to more serious problems, the software has not been able to perform some functions.

WARNING==>An Indication that something unexpected happened, indicate that some problem may occur in the future.

INFO==>The confirmation that things are working as expected.

DEBUG==>Detailed debugging information, typically of interest only when diagnosing the problems.

NOTSET==>Represents that the level is not set.

Command Line Arguments

Implementing the Python Logging

To perform logging, first, we required to create a file to store messages, and we have to specify which level messages required to store.

We can do this by using the basicConfig() function of the logging module.

logging.basicConfig(filename='log.txt', level=logging.WARNING)

The above line will create a file by the name log.txt; we can store either warning level messages or higher-level messages in that file.

After creating a file, we can write messages to that file by using the following methods

logging.critical(message)

logging.error(message)

logging.warning(message)

logging.info(message)

logging.debug(message)

The following example demonstrates creating a log file and write WARNING and higher-level messages.

import logging
logging.basicConfig(filename='log.txt',level=logging.WARNING)
print("logging demo")
logging.critical("This is critical message")
logging.error("This is error message")
logging.warning("This is Waning message")
logging.info("This is Info message")
logging.debug("This is debug message")

The output is:

implementing-logging

And also, if you open the link C:/Users/User/.spyder-py3 the logging messages will be present in the log file.

logging-messages-in-log-file

In the above program, only WARNING and higher-level messages will be written to the log file; if we set level as DEBUG, then all the messages will be written to the log file.
import logging
logging.basicConfig(filename='log.txt',level=logging.DEBUG)
print("logging demo")
logging.critical("This is critical message")
logging.error("This is error message")
logging.warning("This is Waning message")
logging.info("This is Info message")
logging.debug("This is debug message")

Now, the log is containing all the level messages:

mentioning-the-logging-level-to-debug

The following example demonstrates the configure a log file in overwriting mode

import logging
logging.basicConfig(filename='log.txt',level=logging.DEBUG,filemode="w")
print("logging demo")
logging.critical("This is critical message")
logging.error("This is error message")
logging.warning("This is Waning message")
logging.info("This is Info message")
logging.debug("This is debug message")

The output is:

mentioning-the-overwriting-file-mode

If we do not mention any filename or logging level and filemode, then python will simply write to the console

import logging
logging.basicConfig()
print("logging demo")
logging.critical("This is critical message")
logging.error("This is error message")
logging.warning("This is Waning message")
logging.info("This is Info message")
logging.debug("This is debug message")

The output is:

writing-to-the-console

Python Constructor

Formatting of Log Messages

By using the format keyword argument, we can format the log message as per our requirements,

The Normal format is:

level name: logger name: message
CRITICAL: root: This is critical message

To display only the level name:

logging.basicConfig(format='%(levelname)s')

The following example demonstrates displaying only level name

import logging
logging.basicConfig(format='%(levelname)s')
logging.critical("This is critical message")
logging.error("This is error message")
logging.warning("This is Waning message")
logging.info("This is Info message")
logging.debug("This is debug message")

The output is:

displaying-only-level-name

To Display levelname and message:

logging.basicConfig(format='%(levelname)s:%(message)s')

The following example demonstrates displaying levelname and message

import logging
logging.basicConfig(format='%(levelname)s:%(message)s')
logging.critical("This is critical message")
logging.error("This is error message")
logging.warning("This is Waning message")
logging.info("This is Info message")
logging.debug("This is debug message")

The output is :

display-levelname-and-message

If you want to print the logger name then,

import logging
logging.basicConfig(format='%(levelname)s:%(name)s:%(message)s')
logging.critical("This is critical message")
logging.error("This is error message")
logging.warning("This is Waning message")
logging.info("This is Info message")
logging.debug("This is debug message")

The output is:

to-display-loggername

If you're going to print process id, then,

import logging
logging.basicConfig(format='%(levelname)s:%(process)d:%(name)s:%(message)s')
logging.critical("This is critical message")
logging.error("This is error message")
logging.warning("This is Waning message")
logging.info("This is Info message")
logging.debug("This is debug message")

The output is:

to-print-the-process-id

The following are the different types of attributes, by using these attributes we can customize based on our requirement.

Attribute name

Format

Description

args

You shouldn’t need to format this yourself.

The tuple of arguments merged into message, or a dict whose values are used for the merge (when there is only one argument, and it is a dictionary).

asctime

%(asctime)s

The human-readable time when the LogRecord was created. By default, this is of the form ‘2003-07-08 16:49:45,896’ (the numbers after the comma are millisecond portion of the time).

created

%(created)f

The time when the time.time()).

exc_info

You shouldn’t need to format this yourself.

Exception tuple (à la None.

filename

%(filename)s

Filename portion of pathname.

funcName

%(funcName)s

Name of the function containing the logging call.

levelname

%(levelname)s

The text logging level for the message ('CRITICAL').

levelno

%(levelno)s

The numeric logging level for the message (CRITICAL).

lineno

%(lineno)d

Source line number where the logging call was issued (if available).

message

%(message)s

The logged message, computed as Formatter.format() is invoked.

module

%(module)s

Module (name portion of filename).

msecs

%(msecs)d

Millisecond portion of the time when the LogRecord Was created.

msg

You shouldn’t need to format this yourself.

The format string passed in the original logging call. Merged with Using arbitrary objects as messages).

name

%(name)s

The name of the logger used to log the call.

pathname

%(pathname)s

The full pathname of the source file where the logging call was issued (if available).

process

%(process)d

Process ID (if available).

processName

%(processName)s

Process name (if available).

relativeCreated

%(relativeCreated)d

Time in milliseconds when the LogRecord was created, relative to the time the logging module was loaded.

stack_info

You shouldn’t need to format this yourself.

Stack frame information (where available) from the bottom of the stack in the current thread, up to and including the stack frame of the logging call which resulted in the creation of this record.

How to access static Variables in Python

Adding Date and Timestamp in the Log message in python

Adding date and time to the logging message we can differentiate between the messages when an event is succeeded or not succeeded in the python script.

The asctime is the parameter that has been provided by the python to add date and time to the logging message.

The syntax is:

logging.basicConfig(format='%(asctime)s')

The following example demonstrates adding date and time to the log message

import logging
logging.basicConfig(format='%(asctime)s:%(levelname)s:%(message)s')
logging.critical("This is critical message")
logging.error("This is error message")
logging.warning("This is Warning message")
logging.info("This is Info message")
logging.debug("This is debug message")

The output is:

adding-date-and-time-to-the-log-message

It is also possible to change the date format to dd/mm/yy by using the datefmt keyword

import logging
logging.basicConfig(format='%(asctime)s:%(levelname)s:%(message)s', 
                     datefmt='%d/%m/%y %I:%M:%S %p')
logging.critical("This is critical message")
logging.error("This is error message")
logging.warning("This is Warning message")
logging.info("This is Info message")
logging.debug("This is debug message")

The output is:

adding-date-format-to-the-log-message

The case is important in ==>%d/%m/%y %I:%M:%S %p
%I==> means 12 hours time scale
%H==> means 24 hours time scale

The following link shows you the different time attributes Time Attributes

Python Modules

Adding Exception information to the log file in python

We can add exception information to the log file and continue execution.

The syntax to add an exception to the log file is:

logging.exception(msg)

The following example demonstrates adding exception information to the log file

import logging
logging.basicConfig(filename="mylog123546.log",
                    level=logging.INFO,
                    format='%(asctime)s:%(levelname)s:%(message)s',
                    datefmt='%d/%m/Y %I:%M:S %p')
logging.info("A New equest came")
try:
    x=int(input("Enter First Number:"))
    y=int(input("Enter Second Number:"))
    print("The Result:",x/y)
    
except ZeroDivisionError as msg:
    print("Cannot divide with Zero")
    logging.exception(msg)

except ValueError as msg:
    print("provide int values only")
    logging.exception(msg)
    
logging.info("Request processing completed")   

The output is:

adding-exception-information

Now, the new log file got created, open that log123456.log file you can see the request message in that.

my-log-123456

If a ZeroDivisionError exception raise and the exception has been written to the log file

zero-division-error-exception

exception-msg-in-log-file

In the same way, if Value error occurs then the exception message will be stored in the log file.

Python Operator

Root Logger in python

The python logging module organizes a logger in a hierarchy, all loggers are descendants of the root logger, each logger passes a log message on to its parent.

We can configure the root logger to log to a file by using the basicConfig() function.

If you are not defining your own logger then by default the root logger will be considered and once we perform basic configuration to the root logger, then the configuration is fixed, and we cannot change it.

The following example demonstrates the basic configuration of the root logger

import logging
logging.basicConfig(filename='QRZ.log',level=logging.DEBUG,filemode='w')

logging.critical("This is critical message")
logging.error("This is error message")
logging.warning("This is Warning message")
logging.info("This is Info message")
logging.debug("This is debug message")

The output is:

qrz-log-file

If you try to perform the basic configuration to the root logger, it won't be possible.

import logging
logging.basicConfig(filename='QRZ.log',level=logging.DEBUG,filemode='w')
logging.basicConfig(filename='WYZ.log',level=logging.ERROR,filemode='w')
logging.critical("This is critical message")
logging.error("This is error message")
logging.warning("This is Warning message")
logging.info("This is Info message")
logging.debug("This is debug message")

The WYZ.log file won't create, as we already did a basic configuration to the root logger and that is final.

performing-basic-configuration-to-the-root-logger

The Issues with Root Logger :
  • Once we set basic configuration, then that configuration is final and we cannot change.
  • We can use Either file handler or console handler but not both simultaneously.
  • It is not possible to configure a logger with different configurations at a different level.
  • We cannot specify multiple log files for multiple modules/classes/methods

None Datatype

Customized Logger in python

To customize our logger, we have to create three objects

  • Logger Object
  • Handler Object
  • Formatter Object

After creating the above three objectives, we have connected the formatter object to the handler object and then adding a handler object to the logger object.

Creating a Logger Object and Set level:

The syntax to create a logger object is as shown below:

logger=logging.getlogger("NameOf the Logger")

For the customized logger, the default level is NOTSET, and if you do not mention the logger level, then all log messages will be considered by default.

The syntax to set the logger level is:

logger.setlevel(logging.WARNING)
Creating a Handler Object and Set Level:

We can create two types of Handler objects:

  • Console Handler
  • File Handler

The syntax to create a console handler is:

consoleHandler=logging.stream Handler()

The syntax to create File Handler is:

logging.FileHandler(Filename,filemode)

The syntax to set level for the handler object to the console

consoleHandler.setLevel(logging.ERROR)

The syntax to set level for the handler object to the file

fileHandler.setLevel(logging.ERROR)
Creating a Formatter Object:

The logger format include date and time, levelname, log message, and logger name

The syntax is:

formatter=logging.Farmatter('%(asctime)s:%(levelname)s:%(name)s:%(message)s',datefmt='%d/%m/%y %I:%M:%S %p')
Set Formatter to Handler:

The syntax to set formatter to the handler is:

consoleHandler.setFormatter(formatter)
Add Handler to the Logger:

The language to add a handler to the logger is:

logging.addHandler(consoleHandler)
Writing log messages by using the logger object:

The syntax is:

logger.critical(msg)
logger.warning(msg)
logger.info(msg)
logger.error(msg)
logger.debug(msg)

The following example demonstrates how to define and use custom logger with console handler

import logging
logger=logging.getLogger("demologger")
logger.setLevel(logging.DEBUG)
consoleHandler=logging.StreamHandler()
formatter=logging.Formatter('%(asctime)s:%(levelname)s:%(name)s:%(message)s',datefmt='%d/%m/%y %I:%M:%S %p')
consoleHandler.setFormatter(formatter)
logger.addHandler(consoleHandler)
logger.critical("It is critical message")
logger.error("This is error message")
logger.warning("This is Warning message")
logger.info("This is Info message")
logger.debug("This is debug message")

The output is:

cutomized-logger-output

If set the logger level to the Error then, we will get an Error or higher-level message in the console

import logging
logger=logging.getLogger("demologger")
logger.setLevel(logging.DEBUG)
consoleHandler=logging.StreamHandler()
consoleHandler.setLevel(logging.ERROR)  ##setting logger level
formatter=logging.Formatter('%(asctime)s:%(levelname)s:%(name)s:%(message)s',datefmt='%d/%m/%y %I:%M:%S %p')
consoleHandler.setFormatter(formatter)
logger.addHandler(consoleHandler)
logger.critical("It is critical message")
logger.error("This is error message")
logger.warning("This is Warning message")
logger.info("This is Info message")
logger.debug("This is debug message")

The output is:

cutomized-logger-after-setting-logger-level

The following example demonstrates how to define and use custom logger with file handler

import logging
logger=logging.getLogger("demologger")
logger.setLevel(logging.DEBUG)

fileHandler=logging.FileHandler('cuttest.log',mode='w') ##file handler

formatter=logging.Formatter('%(asctime)s:%(levelname)s:%(name)s:%(message)s',datefmt='%d/%m/%y %I:%M:%S %p')
fileHandler.setFormatter(formatter)
logger.addHandler(fileHandler)
logger.critical("It is critical message")
logger.error("This is error message")
logger.warning("This is Warning message")
logger.info("This is Info message")
logger.debug("This is debug message")

The output is: Here the output has not written to the console because we are writing it to the file handler, hence if we open the cttest.log file, we can see the messages.

cutomized-log-message-to-the-file-handler

If we set the logger level to the file handler then, python will print only the error and higher-level messages in the log file.

import logging
logger=logging.getLogger("demologger")
logger.setLevel(logging.DEBUG)

fileHandler=logging.FileHandler('cuttest.log',mode='w')
fileHandler.setLevel(logging.ERROR) ##setting the logger level
formatter=logging.Formatter('%(asctime)s:%(levelname)s:%(name)s:%(message)s',datefmt='%d/%m/%y %I:%M:%S %p')
fileHandler.setFormatter(formatter)
logger.addHandler(fileHandler)
logger.critical("It is critical message")
logger.error("This is error message")
logger.warning("This is Warning message")
logger.info("This is Info message")
logger.debug("This is debug message")

The output is:

set-logger-level-to-the-file-handler


The following program to define and use a custom logger with both console and file handler

import logging

logger=logging.getLogger("demologger")
logger.setLevel(logging.DEBUG)

consoleHandler=logging.StreamHandler()
fileHandler=logging.FileHandler('Adhvik.log',mode='w')

formatter=logging.Formatter('%(asctime)s:%(levelname)s:%(name)s:%(message)s',datefmt='%d/%m/%y %I:%M:%S %p')
fileHandler.setFormatter(formatter)
consoleHandler.setFormatter(formatter)

logger.addHandler(fileHandler)
logger.addHandler(consoleHandler)

logger.critical("It is critical message")
logger.error("This is error message")
logger.warning("This is Warning message")
logger.info("This is Info message")
logger.debug("This is debug message")

The output of the console is:

customized-log-message-to-both-console-and-log-file-Console-output

The output of logfile is:

customized-log-message-to-both-console-and-log-file-output

If we set the level to the console handler then we can see different log messages in the console and the log file, in console, we can see the Error and higher-level messages, and in the log file, we can see all type of log messages.

import logging

logger=logging.getLogger("demologger")
logger.setLevel(logging.DEBUG)

consoleHandler=logging.StreamHandler()
consoleHandler.setLevel(logging.ERROR)  ##setting consolehandler-level
fileHandler=logging.FileHandler('Adhvik.log',mode='w')

formatter=logging.Formatter('%(asctime)s:%(levelname)s:%(name)s:%(message)s',datefmt='%d/%m/%y %I:%M:%S %p')
fileHandler.setFormatter(formatter)
consoleHandler.setFormatter(formatter)

logger.addHandler(fileHandler)
logger.addHandler(consoleHandler)

logger.critical("It is critical message")
logger.error("This is error message")
logger.warning("This is Warning message")
logger.info("This is Info message")
logger.debug("This is debug message")

The output of the console is:

console-customized-logmessage-after-settig-the-logger-level

The output of logfile:

log-message-to-the-file

We can create two different formatter for both console and the log file; for the console, I am keeping only the levelname and the message and for the log file, levelname,asctime, name, and the datefmt.

For the console keeping the formatter name as formatter2 and for the log file as formatter1.

import logging

logger=logging.getLogger("demologger")
logger.setLevel(logging.DEBUG)

consoleHandler=logging.StreamHandler()
consoleHandler.setLevel(logging.ERROR)
fileHandler=logging.FileHandler('Adhvik.log',mode='w')

formatter1=logging.Formatter('%(asctime)s:%(levelname)s:%(name)s:%(message)s',datefmt='%d/%m/%y %I:%M:%S %p')
formatter2=logging.Formatter('%(levelname)s:%(message)s')
fileHandler.setFormatter(formatter1)
consoleHandler.setFormatter(formatter2)

logger.addHandler(fileHandler)
logger.addHandler(consoleHandler)

logger.critical("It is critical message")
logger.error("This is error message")
logger.warning("This is Warning message")
logger.info("This is Info message")
logger.debug("This is debug message")

The output of the console is:

only-critical-and-error-message-in-the-console

The output of logfile is:

different-formatter-for-log-file

The following example demonstrates they define and use a custom logger with different modules and with different log files.

Let us create two different modules as test modules and student modules. The data in the test module should be written to test.log file, and the data in the student module should be written to the student.log file.

In the test module, the level should be either DEBUG or higher-level messages, and in the student module ERROR or higher-level messages.

The test.py is:

import logging
import student
logger=logging.getLogger("testlogger")
logger.setLevel(logging.DEBUG)

fileHandler=logging.FileHandler('test.log',mode='a')

formatter=logging.Formatter('%(asctime)s:%(levelname)s:%(name)s:%(message)s',datefmt='%d/%m/%y %I:%M:%S %p')

fileHandler.setFormatter(formatter)

logger.addHandler(fileHandler)

logger.critical("It is critical message")
logger.error("This is error message")
logger.warning("This is Warning message")
logger.info("This is Info message")
logger.debug("This is debug message")

The output is:

output-of-test-module

The Student Module:

import logging
logger=logging.getLogger("studentlogger")
logger.setLevel(logging.DEBUG)

fileHandler=logging.FileHandler('student.log',mode='w')
fileHandler.setLevel(logging.ERROR)
formatter=logging.Formatter('%(asctime)s:%(levelname)s:%(name)s:%(message)s')

fileHandler.setFormatter(formatter)

logger.addHandler(fileHandler)

logger.critical("It is critical message")
logger.error("This is error message")
logger.warning("This is Warning message")
logger.info("This is Info message")
logger.debug("This is debug message")

The output is:

the-student-logger

The Inspect Module in Python

The python inspects module is used to get information about the Module, Classes, and Methods in a program. We can inspect the Module information, Classes, and Functions in a Module /Class. We can get the Source of the method, Class. This tool is mostly used by IDEs, documentation tools, and code analysis tools.

Python inspects module is a very useful module, which is used to inspect the live object from the program and look at the source code of the Modules, Classes, and Functions that are used throughout a program.

This is powerful because this module can be used to extract the source code of a function itself, parse the arguments which that function accepts and related library documentation.

The following example demonstrates the inspect module.

Let us create a demo.py and import inspect module.

import inspect
def getInfo():
    print(inspect.stack())

Now, create a testt.py and import the demo.py and get the details of the stack by calling a function.

from demo import getInfo
def function1():
    getInfo()

function1()

The output is:

getting-stack-details

Comment / Suggestion Section
Point our Mistakes and Post Your Suggestions