To start, logging is a way of tracking events in a program when it runs and is in execution. Python logging module defines functions and classes that provide a flexible event logging system for python applications.
Python Logging Module
Logging information while events happen is a handy task which helps to see the pattern in which our program executes, what data it acted upon and what results it returned and all this is done without affecting the actual state of the program.
Note that the logs are only for developers (usually) and they can be visualized using many tools. Let’s look into different aspects of python logging module now.
Python Logging Levels
Each log message is assigned a level of severity. Broadly speaking, there are following python logging levels:
- Info: It is used to log useful infor about app lifecycle and these logs won’t metter under normal circumstances .
- Warn: Use this log level when an event can potentially cause application abnormalities but are handled in the code ourself.
- Error: Any log message which was fatal to the normal flow of execution of the program but not related to the the application state itself.
- Debug: This is used just to log diagnosis information like system health and is useful to people like system admins etc.
- Fatal/Critical: These are errors which is forcing a shutown for the application and required immediate developer/admin intervention. This may also mean data loss or corruption of some kind.
More or less they are very similar to java log4j logging framework.
Python Logging Example
Let’s look at different ways we can use python logging module to log messages.
Simple Logging Example
The simplest form of logging occurs in form of only String messages. Let’s quickly look at an example code snippet:
1 2 3 4 5 |
import logging logging.warning("Warning log.") logging.info("Info log.") |
The output will be:
Do you wonder why only the warning level log appeared in the console? This is because the default level of logging is WARNING
.
Python logging to file
Console logging is quite clear but what if we want to search through the logs after a day or a week? Won’t it be better if the logs were just collected at a single place where we can run simple text operations? Actually, we can log our messages to a file instead of a console.
Let’s modify our script to do the necessary configuration:
1 2 3 4 5 6 7 8 |
import logging # Configure file logging.basicConfig(filename="my_logs.log", level = logging.DEBUG) logging.warning("Warning log.") logging.info("Info log.") logging.debug("Debug log.") |
When we run this script, we will not get back any output as all the logging is done in the file which is made by the script itself. Its content looks like:
1 2 3 4 5 |
WARNING:root:Warning log. INFO:root:Info log. DEBUG:root:Debug log. |
As we also used the log level as Debug, all the levels of logs are present in the file.
Python logging messages without append
In our last example, we wrote a simple script to log messages in a file. Now, go on and run the same script again and again. You’ll notice that the file is appended with messages and new logs are added to last content. This is the default behavior of the logging module.
To modify this so that the messages are included as a fresh file, make slight changes in the configuration as:
1 2 3 4 5 6 7 8 |
import logging # Configure file logging.basicConfig(filename="my_logs.log", filemode="w", level = logging.DEBUG) logging.warning("Warning log.") logging.info("Info log.") logging.debug("Debug log.") |
We just added a new attribute as filemode
. Now, run the script multiple times:
The content of the log file now looks like:
1 2 3 4 5 |
WARNING:root:Warning log. INFO:root:Info log. DEBUG:root:Debug log. |
So, the messages are present as only fresh messages.
Python Logging Format
Of course, the format of current logs is, strange! We will try to clean our messages and put some formatting. Fortunately, it is just a matter of a single line configuration. Let’s quickly look at python logging format example:
1 2 3 4 5 6 7 8 9 |
import logging # Configure file logging.basicConfig(filename="my_logs.log", filemode="w", format="%(levelname)s: %(message)s", level=logging.DEBUG) logging.warning("Warning log.") logging.info("Info log.") logging.debug("Debug log.") |
Now in this case, the content of the log file looks like:
1 2 3 4 5 |
WARNING: Warning log. INFO: Info log. DEBUG: Debug log. |
Much cleaner, right?
Python logging configurations for date time
The log messages would make a lot of sense in real scenarios when we know when did an event actually occurred! We will try to provide date and timestamp to our messages. Again, it is just a matter of a single line configuration. Let’s quickly look at an example code snippet:
1 2 3 4 5 6 7 8 9 |
import logging # Configure file logging.basicConfig(filename="my_logs.log", filemode="w", format="%(levelname)s -> %(asctime)s: %(message)s", level=logging.DEBUG) logging.warning("Warning log.") logging.info("Info log.") logging.debug("Debug log.") |
We only added a single attribute as asctime
. Now in this case, the content of the log file looks like:
1 2 3 4 5 |
WARNING -> 2017-12-09 12:56:25,069: Warning log. INFO -> 2017-12-09 12:56:25,069: Info log. DEBUG -> 2017-12-09 12:56:25,069: Debug log. |
Making much more sense now.
Python logging getLogger()
Now, we were making a direct use of logging module. Why not just get an object and use it to log messages. Let’s quickly look at an example code snippet:
1 2 3 4 5 6 7 8 9 10 |
import logging # Configure file logging.basicConfig(filename="my_logs.log", filemode="w", format="%(levelname)s -> %(asctime)s: %(message)s", level=logging.DEBUG) logger = logging.getLogger(__name__) logger.info("Using custom logger.") shubham = {'name': 'Shubham', 'roll': 123} logger.debug("Shubham: %s", shubham) |
We only added a call to getLogger
. Now in this case, the content of the log file looks like:
1 2 3 4 |
INFO -> 2017-12-09 13:14:50,276: Using custom logger. DEBUG -> 2017-12-09 13:14:50,276: Shubham: {'name': 'Shubham', 'roll': 123} |
Clearly, we can log variables values as well. This will help including much more information in log messages about current state of the program.
Python logging config file
Now, it is a tedious process to provide same logging information in multiple files. What we can do is, we can centralise our configuration into a single place so that whenever we need to make any change, it is needed at a single place only.
We can do this by creating a config file as shown:
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 |
[loggers] keys=root,JournalDev [handlers] keys=fileHandler, consoleHandler [formatters] keys=myFormatter [logger_root] level=CRITICAL handlers=consoleHandler [logger_JournalDev] level=INFO handlers=fileHandler qualname=JournalDev [handler_consoleHandler] class=StreamHandler level=DEBUG formatter=myFormatter args=(sys.stdout,) [handler_fileHandler] class=FileHandler formatter=myFormatter args=("external_file.log",) [formatter_myFormatter] format=%(asctime)s - %(name)s - %(levelname)s - %(message)s datefmt= |
This way, we configured root and a JournalDev logger, provided a logger to both of these along with Handlers and a format. Now, we can make use of this logger file in our script:
1 2 3 4 5 6 7 8 |
import logging import logging.config logging.config.fileConfig('logging.conf') logger = logging.getLogger("JournalDev") logger.info("Custom logging started.") logger.info("Complete!") |
As we configured two loggers in the file, we will see this output on the console as well:
These logs will be present in a file named external_file.log
as well:
1 2 3 4 |
2017-12-09 13:52:49,889 - JournalDev - INFO - Custom logging started. 2017-12-09 13:52:49,889 - JournalDev - INFO - Complete! |
This way, we can keep the logging configuration completely separate.
In this lesson, we learned about various functions provided by python logging module and saw how they work.
Reference: API Doc