Debug With Logging Module

This document covers debugging Python programs using the logging module including log levels, configuration, file output, custom formatters, and best practices for production-grade logging. Professional debugging and monitoring technique.

This document explores debugging Python programs using the logging module, covering log levels (DEBUG, INFO, WARNING, ERROR, CRITICAL), configuration options, file output, custom formatters, handlers, and best practices for production-grade logging that replaces print statements with structured, filterable log messages.


Introduction

Imagine working on an e-commerce site where business growth brings increasing customers and unexpected errors. While print() statements have been the go-to debugging strategy, they now flood the console with messages, making it hard to discern critical issues from routine operations. A more robust solution is needed to track, categorize, and diagnose issues effectively.


What Is the Python Logging Module

Definition

The Python logging module is a built-in library designed to provide a flexible framework for creating log messages. Unlike the print() function, which displays output to the console, the logging module provides configuration and capture of log messages at different severity levels.

Advantages Over Print Statements

FeaturePrint StatementsLogging Module
Severity levelsNoYes (5 levels)
FilteringNoYes
Multiple outputsConsole onlyConsole, file, network
ConfigurationNoHighly configurable
Production usePoorExcellent
TimestampingManualAutomatic
Thread safetyLimitedBuilt-in
Permanent recordsNoYes

Log Levels

Understanding Severity Levels

The logging module categorizes messages based on severity:

LevelNumeric ValuePurposeExample Use Case
DEBUG10Detailed diagnostic informationVariable values, function calls
INFO20General informational messagesUser actions, normal operations
WARNING30Warning messages for potential issuesDeprecated features, unusual conditions
ERROR40Error messages for serious problemsFailed operations, exceptions
CRITICAL50Critical errors causing shutdownSystem crashes, fatal errors

E-commerce Example

ActivityLog LevelRationale
Product browsingDEBUGDetailed user navigation
Cart additionsINFONormal user operations
Successful purchasesINFO/WARNINGImportant transactions
Failed transactionsERRORProblems requiring attention
System crashesCRITICALImmediate intervention needed

This categorization enables filtering and prioritizing issues while retaining detailed records of all interactions.


Getting Started with Logging

Importing the Module

1import logging

Basic Logging

By default, logging only shows WARNING level and above:

1import logging
2
3logging.debug('This will NOT appear')  # Below default level
4logging.info('This will NOT appear')   # Below default level
5logging.warning('This WILL appear')    # At or above default level
6logging.error('This WILL appear')
7logging.critical('This WILL appear')

Output:

1WARNING:root:This WILL appear
2ERROR:root:This WILL appear
3CRITICAL:root:This WILL appear

Basic Configuration

Setting Log Level

Capture more detailed log messages by setting the logging level:

1import logging
2
3logging.basicConfig(level=logging.DEBUG)
4
5logging.debug('This is a debug message')
6logging.info('This is an info message')
7logging.warning('This is a warning message')
8logging.error('This is an error message')
9logging.critical('This is a critical message')

Output:

1DEBUG:root:This is a debug message
2INFO:root:This is an info message
3WARNING:root:This is a warning message
4ERROR:root:This is an error message
5CRITICAL:root:This is a critical message

Logging to a File

Keep permanent records by saving messages to a file:

1import logging
2
3logging.basicConfig(
4    filename='app.log',
5    level=logging.DEBUG
6)
7
8logging.info('This message will be written to app.log')
9logging.error('Errors are also written to the file')

The app.log file contents:

1INFO:root:This message will be written to app.log
2ERROR:root:Errors are also written to the file

Custom Format

Customize log message format to include timestamps, levels, and context:

1import logging
2
3logging.basicConfig(
4    format='%(asctime)s - %(levelname)s - %(message)s',
5    level=logging.DEBUG
6)
7
8logging.error('This is an error with a custom format')

Output:

12025-11-13 14:30:45,123 - ERROR - This is an error with a custom format

Format Specifiers

Common Format Attributes

AttributeDescriptionExample
%(asctime)sTimestamp2025-11-13 14:30:45,123
%(levelname)sLog levelERROR
%(name)sLogger name__main__
%(message)sLog messageUser login failed
%(filename)sSource filenameapp.py
%(lineno)dLine number42
%(funcName)sFunction nameuser_login
%(pathname)sFull path/path/to/app.py
%(process)dProcess ID12345
%(thread)dThread ID67890

Comprehensive Format Example

1import logging
2
3logging.basicConfig(
4    format='%(asctime)s - %(name)s - %(levelname)s - %(filename)s:%(lineno)d - %(message)s',
5    level=logging.DEBUG
6)
7
8logger = logging.getLogger(__name__)
9logger.info('Application started')

Output:

12025-11-13 14:30:45,123 - __main__ - INFO - app.py:10 - Application started

Logging in Action

E-commerce Login Example

Instead of using print() statements to debug login issues, implement logging:

 1import logging
 2
 3logging.basicConfig(
 4    level=logging.INFO,
 5    format='%(asctime)s - %(levelname)s - %(message)s'
 6)
 7
 8def user_login(username, password):
 9    logging.info(f"Attempting to log in user: {username}")
10
11    # Authentication logic
12    authentication_failed = check_credentials(username, password)
13
14    if authentication_failed:
15        logging.error(f"Login failed for user: {username}")
16        return False
17    else:
18        logging.info(f"Successfully logged in user: {username}")
19        return True
20
21def check_credentials(username, password):
22    # Simplified authentication
23    logging.debug(f"Checking credentials for {username}")
24
25    if username == "" or password == "":
26        logging.warning("Empty username or password")
27        return True
28
29    # Database check simulation
30    return False  # Assume success for example
31
32# Test the login function
33user_login("alice", "password123")
34user_login("", "password123")

Output:

12025-11-13 14:30:45,123 - INFO - Attempting to log in user: alice
22025-11-13 14:30:45,124 - INFO - Successfully logged in user: alice
32025-11-13 14:30:45,125 - INFO - Attempting to log in user:
42025-11-13 14:30:45,126 - WARNING - Empty username or password
52025-11-13 14:30:45,127 - ERROR - Login failed for user:

Named Loggers

Creating Module-Specific Loggers

Use named loggers to identify message sources:

 1import logging
 2
 3# Create logger for this module
 4logger = logging.getLogger(__name__)
 5logger.setLevel(logging.DEBUG)
 6
 7# Configure handler
 8handler = logging.StreamHandler()
 9handler.setLevel(logging.DEBUG)
10
11# Create formatter
12formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
13handler.setFormatter(formatter)
14
15# Add handler to logger
16logger.addHandler(handler)
17
18# Use the logger
19logger.info('This is from a named logger')

Logger Hierarchy

 1import logging
 2
 3# Parent logger
 4parent_logger = logging.getLogger('myapp')
 5parent_logger.setLevel(logging.INFO)
 6
 7# Child loggers inherit from parent
 8auth_logger = logging.getLogger('myapp.auth')
 9database_logger = logging.getLogger('myapp.database')
10
11auth_logger.info('User authenticated')  # Propagates to parent
12database_logger.error('Connection failed')  # Propagates to parent

Advanced Configuration

Multiple Outputs

Log to both console and file simultaneously:

 1import logging
 2
 3logger = logging.getLogger('myapp')
 4logger.setLevel(logging.DEBUG)
 5
 6# Console handler
 7console_handler = logging.StreamHandler()
 8console_handler.setLevel(logging.INFO)
 9console_format = logging.Formatter('%(levelname)s - %(message)s')
10console_handler.setFormatter(console_format)
11
12# File handler
13file_handler = logging.FileHandler('app.log')
14file_handler.setLevel(logging.DEBUG)
15file_format = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
16file_handler.setFormatter(file_format)
17
18# Add handlers
19logger.addHandler(console_handler)
20logger.addHandler(file_handler)
21
22# Test logging
23logger.debug('Detailed debug info')  # Only in file
24logger.info('General information')    # Console and file
25logger.error('Error occurred')        # Console and file

Rotating File Handler

Prevent log files from growing too large:

 1import logging
 2from logging.handlers import RotatingFileHandler
 3
 4logger = logging.getLogger('myapp')
 5logger.setLevel(logging.DEBUG)
 6
 7# Rotate when file reaches 1MB, keep 5 backup files
 8handler = RotatingFileHandler(
 9    'app.log',
10    maxBytes=1024*1024,  # 1MB
11    backupCount=5
12)
13
14formatter = logging.Formatter('%(asctime)s - %(levelname)s - %(message)s')
15handler.setFormatter(formatter)
16logger.addHandler(handler)
17
18logger.info('This goes to a rotating log file')

Timed Rotating File Handler

Rotate logs based on time intervals:

 1import logging
 2from logging.handlers import TimedRotatingFileHandler
 3
 4logger = logging.getLogger('myapp')
 5logger.setLevel(logging.DEBUG)
 6
 7# Rotate daily at midnight, keep 7 days of logs
 8handler = TimedRotatingFileHandler(
 9    'app.log',
10    when='midnight',
11    interval=1,
12    backupCount=7
13)
14
15formatter = logging.Formatter('%(asctime)s - %(levelname)s - %(message)s')
16handler.setFormatter(formatter)
17logger.addHandler(handler)
18
19logger.info('Daily rotating log')

Logging Exceptions

Logging with Stack Traces

1import logging
2
3logging.basicConfig(level=logging.ERROR)
4
5try:
6    result = 10 / 0
7except ZeroDivisionError:
8    logging.error('Division by zero occurred', exc_info=True)

Output:

1ERROR:root:Division by zero occurred
2Traceback (most recent call last):
3  File "app.py", line 5, in <module>
4    result = 10 / 0
5ZeroDivisionError: division by zero

Exception Shortcut

1import logging
2
3logging.basicConfig(level=logging.ERROR)
4
5try:
6    result = 10 / 0
7except ZeroDivisionError:
8    logging.exception('An error occurred')  # Automatically includes exc_info

Best Practices

Do’s and Don’ts

DoDon’t
Use named loggers (getLogger(__name__))Use root logger in libraries
Set appropriate log levelsLog everything at ERROR level
Include context in messagesLog sensitive information
Use handlers for productionUse basicConfig in libraries
Rotate log filesLet log files grow infinitely
Log exceptions with exc_info=TrueSuppress exception details

Choosing Log Levels

 1import logging
 2
 3logger = logging.getLogger(__name__)
 4
 5# DEBUG - Detailed information for diagnosing problems
 6logger.debug(f"Processing item {item_id} with config {config}")
 7
 8# INFO - Confirmation that things are working as expected
 9logger.info(f"User {user_id} logged in successfully")
10
11# WARNING - Something unexpected happened, but application still works
12logger.warning(f"Cache miss for key {key}, fetching from database")
13
14# ERROR - Serious problem, function couldn't complete
15logger.error(f"Failed to process payment for order {order_id}")
16
17# CRITICAL - Very serious error, application may not continue
18logger.critical(f"Database connection lost, shutting down")

Structured Logging

 1import logging
 2import json
 3
 4class JsonFormatter(logging.Formatter):
 5    def format(self, record):
 6        log_data = {
 7            'timestamp': self.formatTime(record),
 8            'level': record.levelname,
 9            'message': record.getMessage(),
10            'module': record.module,
11            'function': record.funcName,
12            'line': record.lineno
13        }
14        return json.dumps(log_data)
15
16logger = logging.getLogger(__name__)
17handler = logging.StreamHandler()
18handler.setFormatter(JsonFormatter())
19logger.addHandler(handler)
20logger.setLevel(logging.INFO)
21
22logger.info('User action completed')

Configuration File

Using Configuration Files

Store logging configuration in external files:

 1# logging_config.ini
 2[loggers]
 3keys=root,myapp
 4
 5[handlers]
 6keys=consoleHandler,fileHandler
 7
 8[formatters]
 9keys=simpleFormatter
10
11[logger_root]
12level=WARNING
13handlers=consoleHandler
14
15[logger_myapp]
16level=DEBUG
17handlers=consoleHandler,fileHandler
18qualname=myapp
19propagate=0
20
21[handler_consoleHandler]
22class=StreamHandler
23level=INFO
24formatter=simpleFormatter
25args=(sys.stdout,)
26
27[handler_fileHandler]
28class=FileHandler
29level=DEBUG
30formatter=simpleFormatter
31args=('app.log', 'a')
32
33[formatter_simpleFormatter]
34format=%(asctime)s - %(name)s - %(levelname)s - %(message)s

Load configuration:

1import logging
2import logging.config
3
4logging.config.fileConfig('logging_config.ini')
5logger = logging.getLogger('myapp')
6
7logger.debug('Debug message')
8logger.info('Info message')

Complete Example: Production Application

 1import logging
 2from logging.handlers import RotatingFileHandler
 3import sys
 4
 5def setup_logging(log_file='app.log', log_level=logging.INFO):
 6    """
 7    Configure logging for production application.
 8
 9    Args:
10        log_file: Path to log file
11        log_level: Minimum logging level
12    """
13    # Create logger
14    logger = logging.getLogger('myapp')
15    logger.setLevel(log_level)
16
17    # Create formatters
18    file_formatter = logging.Formatter(
19        '%(asctime)s - %(name)s - %(levelname)s - '
20        '%(filename)s:%(lineno)d - %(message)s'
21    )
22    console_formatter = logging.Formatter(
23        '%(levelname)s - %(message)s'
24    )
25
26    # Console handler (INFO and above)
27    console_handler = logging.StreamHandler(sys.stdout)
28    console_handler.setLevel(logging.INFO)
29    console_handler.setFormatter(console_formatter)
30
31    # File handler (DEBUG and above, rotating)
32    file_handler = RotatingFileHandler(
33        log_file,
34        maxBytes=10*1024*1024,  # 10MB
35        backupCount=5
36    )
37    file_handler.setLevel(logging.DEBUG)
38    file_handler.setFormatter(file_formatter)
39
40    # Add handlers
41    logger.addHandler(console_handler)
42    logger.addHandler(file_handler)
43
44    return logger
45
46def main():
47    """Main application entry point."""
48    logger = setup_logging()
49
50    logger.info('Application started')
51
52    try:
53        # Application logic
54        logger.debug('Processing user request')
55        result = process_request()
56        logger.info(f'Request processed successfully: {result}')
57
58    except Exception as e:
59        logger.exception('Unexpected error occurred')
60        return 1
61
62    finally:
63        logger.info('Application shutting down')
64
65    return 0
66
67def process_request():
68    """Simulate request processing."""
69    logger = logging.getLogger('myapp')
70    logger.debug('Inside process_request')
71
72    # Simulate work
73    return 'Success'
74
75if __name__ == '__main__':
76    sys.exit(main())

Key Takeaways

Integrating logging into applications streamlines the debugging process. Logging allows categorizing messages based on severity, helping filter and prioritize issues. Log messages can be saved to files, ensuring persistent records even if applications crash. The logging module is highly configurable, supporting various output formats and destinations including console, files, and network endpoints. Using handlers like RotatingFileHandler prevents disk space issues while maintaining historical log data.


Conclusion

The Python logging module provides a production-grade solution for debugging and monitoring applications. By replacing print statements with structured logging, developers gain powerful capabilities for filtering, formatting, and routing log messages. Proper logging configuration with appropriate levels, handlers, and formatters enables effective troubleshooting in development while providing operational visibility in production. The logging module’s flexibility makes it essential for building robust, maintainable Python applications.


FAQ