"Logging is the silent guardian of software, capturing the whispers of code for analysis and insight. It's a real spy!"
- What is logging?
- Python's Built-in Logging Module
- Configuring Logging:
Handlers,Formatters, andConfig Files - Logging Best Practices
- Homework
Logging provides visibility into an application's behavior and state. It is essential for:
- Debugging: Understanding the flow of the application and diagnosing issues.
- Monitoring: Keeping track of the health and performance of the application.
- Auditing: Recording actions for compliance and security analysis.
Properly implemented logging can provide insights into what's happening in your application, which is invaluable for maintenance and troubleshooting.
Python's built-in logging module allows you to log messages with different levels and direct them to several destinations.
There are different levels at which logging can be done:
- DEBUG: Detailed information, typically of interest only when diagnosing problems.
- INFO: Confirmation that things are working as expected.
- WARNING: An indication that something unexpected happened, or indicative of some problem in the near future.
- ERROR: Due to a more serious problem, the software has not been able to perform some function.
- CRITICAL: A serious error, indicating that the program itself may be unable to continue running.
You have to understand which level should be used based on representation above.
We need to import logging module on the top of the file.
import logging
# Configure basic logging
logging.basicConfig(level=logging.INFO)
# Log messages
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')INFO:root:This is an info message
WARNING:root:This is a warning message
ERROR:root:This is an error message
CRITICAL:root:This is a critical message
Let's create a small application which will represent the importance of logging
import logging
logging.basicConfig(level=logging.INFO, format='%(asctime)s - %(levelname)s - %(message)s')
class TaskManager:
def __init__(self):
self.tasks = {}
logging.info("Task Manager is initialized")
def add_task(self, task_id, task_description):
if task_id in self.tasks:
logging.warning(f"Task with id {task_id} already exists. Overwriting.")
self.tasks[task_id] = task_description
logging.info(f"Task added: {task_id} - {task_description}")
def complete_task(self, task_id):
if task_id not in self.tasks:
logging.error(f"Cannot complete task: {task_id}. Task does not exist.")
return
task_description = self.tasks.pop(task_id)
logging.info(f"Task completed: {task_id} - {task_description}")
def display_tasks(self):
if not self.tasks:
logging.warning("No tasks available to display.")
return
logging.debug("Current tasks:")
for task_id, task_description in self.tasks.items():
logging.debug(f"{task_id}: {task_description}")
def main():
task_manager = TaskManager()
# Add some tasks
task_manager.add_task(1, "Write blog post")
task_manager.add_task(2, "Prepare dinner")
task_manager.add_task(1, "Update blog post") # This will trigger a warning log and info log eventually
task_manager.display_tasks()
task_manager.complete_task(2)
task_manager.complete_task(3) # This will trigger an error log
task_manager.display_tasks()
main()2024-02-04 15:14:27,174 - INFO - Task Manager is initialized
2024-02-04 15:14:27,174 - INFO - Task added: 1 - Write blog post
2024-02-04 15:14:27,174 - INFO - Task added: 2 - Prepare dinner
2024-02-04 15:14:27,174 - WARNING - Task with id 1 already exists. Overwriting.
2024-02-04 15:14:27,174 - INFO - Task added: 1 - Update blog post
2024-02-04 15:14:27,174 - INFO - Task completed: 2 - Prepare dinner
2024-02-04 15:14:27,174 - ERROR - Cannot complete task: 3. Task does not exist.
Now, it is easy to track how our application is being used by the customer and we can trace each action made. This ensures, that it is possible to have visibility of the interaction and can prevent us from unexpected occurances.
In order to create an effective and what is more important useful logging system we would want to have the following criterias under control:
- Log level.
- Message format.
- Well-structured configuration files.
Handlers send the log messages to designated destinations.
Each logger can have multiple handlers and each handler can process log messages differently.
Common types of handlers include:
- StreamHandler: Sends log messages to streams like
sys.stdoutorsys.stderr. - FileHandler: Writes log messages to a disk file. It's useful for keeping a persistent log.
- SMTPHandler: Emails log messages to a specified email address. It's useful for critical error reporting.
And many more such as HTTPHanler and SocketHanler.
Note: Those two above are particulary useful once you build a microservice applications and want to have all logs within one reachable place.
Here's how you can set up multiple handlers with different log levels:
import logging
logger = logging.getLogger(__name__)
logger.setLevel(logging.DEBUG) # Set level for logger
console_handler = logging.StreamHandler()
console_handler.setLevel(logging.ERROR) # Only log ERROR and above to console
file_handler = logging.FileHandler('app.log')
file_handler.setLevel(logging.INFO) # Log INFO and above to file
logger.addHandler(console_handler)
logger.addHandler(file_handler)In this setup, the logger captures all messages of level DEBUG and above, but each handler filters the messages differently.
Formatters specify the layout of log messages. You can include information like time, log level, and the message.
formatter = logging.Formatter('%(asctime)s - %(levelname)s - %(message)s')
file_handler.setFormatter(formatter)Commonly used format attributes include:
%(name)s: Name of the logger.%(levelno)s: Numeric logging level.%(levelname)s: Text logging level.%(pathname)s: Full pathname of the source file where the logging call was issued.%(filename)s: Filename portion of pathname.%(module)s: Module name.%(funcName)s: Name of function containing the logging call.%(lineno)d: Source line number where the logging call was issued.%(asctime)s: Human-readable time when the LogRecord was created.%(message)s: The logged message.
In order to have a convenient way of storing the configurations for everything described above we have two and only two the best options
Step 1: Create logging_config.ini file and define expected configuration which is suitable for your application needs.
[loggers]
keys=root,sampleLogger
[handlers]
keys=consoleHandler
[formatters]
keys=sampleFormatter
[logger_root]
level=DEBUG
handlers=consoleHandler
[logger_sampleLogger]
level=DEBUG
handlers=consoleHandler
qualname=sampleLogger
propagate=0
[handler_consoleHandler]
class=StreamHandler
level=DEBUG
formatter=sampleFormatter
args=(sys.stdout,)
[formatter_sampleFormatter]
format=%(asctime)s - %(name)s - %(levelname)s - %(message)s
datefmt=%Y-%m-%d %H:%M:%SStep 2: Load the configuration file using logging.config.fileConfig
import logging.config
logging.config.fileConfig('logging.conf')
logger = logging.getLogger('sampleLogger')
logger.debug('This is a debug message')Now you can change the logging behavior without modifying the application code which is great in terms of scalability.
Let's create a mini-application which will use all functionality of our logging setup. And you will see how the quality and readability of our code was improved.
import logging.config
# Load the logging configuration
logging.config.fileConfig('logging_config.ini')
logger = logging.getLogger('bookstoreLogger')
class Bookstore:
def __init__(self):
self.books = {}
logger.info("Bookstore is initialized")
def add_book(self, isbn, book_details):
if isbn in self.books:
logger.warning(f"Book with ISBN {isbn} already exists. Updating the book.")
else:
logger.info(f"Book added: ISBN {isbn}, Details: {book_details}")
self.books[isbn] = book_details
def update_book(self, isbn, book_details):
if isbn in self.books:
logger.info(f"Book {isbn} updated. Old: {self.books[isbn]}, New: {book_details}")
self.books[isbn] = book_details
else:
logger.error(f"Cannot update book: ISBN {isbn}. Book does not exist.")
def remove_book(self, isbn):
if isbn in self.books:
removed_book = self.books.pop(isbn)
logger.info(f"Book removed: ISBN {isbn} - {removed_book}")
else:
logger.error(f"Cannot remove book: ISBN {isbn}. Book does not exist.")
def list_books(self):
if not self.books:
logger.warning("No books available in the bookstore.")
else:
for isbn, details in self.books.items():
logger.info(f"ISBN {isbn}: {details}")
# Main function to test the Bookstore class
def main():
bookstore = Bookstore()
bookstore.add_book("978-0132350884", {"title": "Clean Code", "author": "Robert C. Martin"})
bookstore.add_book("978-0201633610", {"title": "Design Patterns", "author": "Erich Gamma"})
bookstore.add_book("978-0132350884", {"title": "Clean Code", "author": "Robert C. Martin"})
bookstore.update_book("978-0321125217", {"title": "Domain-Driven Design", "author": "Eric Evans"})
bookstore.remove_book("978-0201633610")
bookstore.list_books()
if __name__ == "__main__":
main()2024-02-04 16:54:17 - bookstoreLogger - INFO - Bookstore is initialized
2024-02-04 16:54:17 - bookstoreLogger - INFO - Book added: ISBN 978-0132350884, Details: {'title': 'Clean Code', 'author': 'Robert C. Martin'}
2024-02-04 16:54:17 - bookstoreLogger - INFO - Book added: ISBN 978-0201633610, Details: {'title': 'Design Patterns', 'author': 'Erich Gamma'}
2024-02-04 16:54:17 - bookstoreLogger - WARNING - Book with ISBN 978-0132350884 already exists. Updating the book.
2024-02-04 16:54:17 - bookstoreLogger - ERROR - Cannot update book: ISBN 978-0321125217. Book does not exist.
2024-02-04 16:54:17 - bookstoreLogger - INFO - Book removed: ISBN 978-0201633610 - {'title': 'Design Patterns', 'author': 'Erich Gamma'}
2024-02-04 16:54:17 - bookstoreLogger - INFO - ISBN 978-0132350884: {'title': 'Clean Code', 'author': 'Robert C. Martin'}
When we have different modules within our application it is crucial to separate the logging for each module and define its custom logger object to improve
import logging
import logging.handlers
import logging.config
import os
# Logging configuration dictionary
LOGGING_CONFIG = {
'version': 1,
'disable_existing_loggers': False,
'formatters': {
'detailed': {
'class': 'logging.Formatter',
'format': '%(asctime)s [%(levelname)s] %(name)s: %(message)s'
},
'email': {
'class': 'logging.Formatter',
'format': 'Timestamp: %(asctime)s\nModule: %(module)s\nLine: %(lineno)d\nMessage: %(message)s'
},
},
'handlers': {
'console': {
'class': 'logging.StreamHandler',
'level': 'INFO',
'formatter': 'detailed',
'stream': 'ext://sys.stdout'
},
'file': {
'class': 'logging.handlers.RotatingFileHandler',
'level': 'DEBUG',
'formatter': 'detailed',
'filename': 'app.log',
'maxBytes': 1024000,
'backupCount': 3
},
'email': {
'class': 'logging.handlers.SMTPHandler',
'level': 'ERROR',
'formatter': 'email',
'mailhost': 'localhost',
'fromaddr': '[email protected]',
'toaddrs': ['[email protected]'],
'subject': 'Critical Error in YourApp!'
},
},
'loggers': {
'': {
'handlers': ['console', 'file', 'email'],
'level': 'DEBUG',
},
}
}
# Applying the logging configuration
logging.config.dictConfig(LOGGING_CONFIG)
# Getting the logger
logger = logging.getLogger(__name__)
# Test messages
logger.debug("This is a debug message")
logger.info("This is an info message")
logger.warning("This is a warning message")
logger.error("This is an error message")
logger.critical("This is a critical message")Be mindful of the log level and the amount of logging in performance-critical parts of the application. It's really important to tackle this in advance.
Keep the logging configuration separate from the application logic. Using configuration files or a dedicated configuration module can achieve this.
Use different logging configurations for different environments (development, testing, production). This can be managed by having separate configuration files for each environment or by using environment variables (.env).
Effective logging is not just about adding log statements to your code. It involves thoughtful consideration of what, where, and how to log.
1.Be clear and descriptive: Log messages should provide enough context to be understood on their own.
2. Use appropriate log levels: This helps in filtering and analyzing logs.
3. Avoid logging sensitive information: Such as passwords or personal user data.
4. Manage log file size: Use mechanisms like log rotation to avoid consuming too much disk space.
And that's it! Happy Logging!
Add logging to your existing projects, config loggers in the most suitable way for you or use configs provided in this lesson.