Professional Logging

Replace print() with production-ready logging

Introduction

While print() statements work for debugging during development, production applications need a more sophisticated approach. Python's logging module provides a powerful, flexible logging system that lets you record events, track issues, and monitor application behavior without cluttering your code with prints. You can control logging levels, format messages, write to files, rotate logs, and more, all with simple configuration. Mastering logging is essential for building maintainable, production-ready applications that you can troubleshoot and monitor effectively.

Why Use Logging Instead of print()?

The logging module offers significant advantages over print statements for real applications.

✗ Problems with print()

Goes to stdout (can't control destination)
No severity levels (all messages equal)
Hard to disable in production
No timestamps or context
Difficult to filter or search
Must manually remove before deployment

✓ Benefits of logging

Control output destination (files, console, network)
Five severity levels (DEBUG to CRITICAL)
Easy to enable/disable per level
Automatic timestamps and metadata
Built-in formatting and filtering
Leave in code, control via configuration

# ❌ Using print() - limited and messy
def process_data(data):
    print(f"Processing {len(data)} items...")
    for item in data:
        print(f"Processing item: {item}")
        # Process item
    print("Done processing")

# Problems:
# - Can't turn off for production
# - No timestamps
# - No way to filter by importance
# - Goes directly to stdout

# ✅ Using logging - professional and flexible
import logging

def process_data(data):
    logging.info(f"Processing {len(data)} items...")
    for item in data:
        logging.debug(f"Processing item: {item}")
        # Process item
    logging.info("Done processing")

# Benefits:
# - Can set level to INFO in production (hides debug messages)
# - Automatic timestamps
# - Can write to files
# - Easy to configure

Basic Logging Usage

The logging module provides simple functions to get started immediately.

Quick Start with basicConfig()

import logging

# Configure logging (do this once at the start of your program)
logging.basicConfig(level=logging.DEBUG)

# Use logging functions
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 (all messages show because level=DEBUG):
# DEBUG:root:This is a debug 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

Basic Configuration Options

import logging

# Configure with format and date format
logging.basicConfig(
    level=logging.INFO,
    format='%(asctime)s - %(levelname)s - %(message)s',
    datefmt='%Y-%m-%d %H:%M:%S'
)

logging.info("Application started")
logging.warning("This is a warning")

# Output:
# 2024-01-15 14:30:45 - INFO - Application started
# 2024-01-15 14:30:45 - WARNING - This is a warning

# Log to a file instead of console
logging.basicConfig(
    level=logging.DEBUG,
    format='%(asctime)s - %(name)s - %(levelname)s - %(message)s',
    filename='app.log',
    filemode='w'  # 'w' = overwrite, 'a' = append
)

logging.info("This goes to app.log file")
logging.error("This also goes to the file")

Important: Call basicConfig()only ONCE at the start of your program. Subsequent calls have no effect. For more complex setups, use loggers and handlers (covered later).

Understanding Log Levels

Python's logging has five standard levels. Each level has a numeric value, and messages are only shown if their level is greater than or equal to the configured level.

The Five Log Levels

Level	Numeric Value	When to Use	Example
`DEBUG`	10	Detailed information for diagnosing problems	Variable values, function entry/exit
`INFO`	20	General informational messages	"Server started", "Processing 100 items"
`WARNING`	30	Something unexpected but not an error	"Disk 90% full", "Deprecated API used"
`ERROR`	40	Error that prevents a specific operation	"Failed to save file", "Database connection failed"
`CRITICAL`	50	Serious error that may cause shutdown	"Out of memory", "Configuration file missing"

How Log Levels Filter Messages

import logging

# Set level to WARNING - only WARNING, ERROR, CRITICAL show
logging.basicConfig(level=logging.WARNING)

logging.debug("Debug message")      # ❌ Won't show (10 < 30)
logging.info("Info message")        # ❌ Won't show (20 < 30)
logging.warning("Warning message")  # ✓ Shows (30 >= 30)
logging.error("Error message")      # ✓ Shows (40 >= 30)
logging.critical("Critical!")       # ✓ Shows (50 >= 30)

# Output (only 3 messages):
# WARNING:root:Warning message
# ERROR:root:Error message
# CRITICAL:root:Critical!

# Common configurations:
# Development: level=logging.DEBUG (see everything)
# Production:  level=logging.INFO or WARNING (hide debug details)
# Production (quiet): level=logging.ERROR (only errors)

Practical Example: Using Levels Appropriately

import logging

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

def process_user_data(user_id):
    """Process user data with appropriate logging"""

    # DEBUG: Detailed diagnostic information
    logging.debug(f"Entering process_user_data(user_id={user_id})")

    # INFO: Confirmation that things are working
    logging.info(f"Processing user {user_id}")

    # Simulate getting user data
    user = get_user(user_id)

    if user is None:
        # ERROR: Failed to complete operation
        logging.error(f"User {user_id} not found")
        return None

    # WARNING: Something unexpected but recoverable
    if user.get("email") is None:
        logging.warning(f"User {user_id} has no email address")

    # DEBUG: Show intermediate values
    logging.debug(f"User data: {user}")

    # Process the data...
    result = do_processing(user)

    # INFO: Operation completed successfully
    logging.info(f"Successfully processed user {user_id}")

    # DEBUG: Show return value
    logging.debug(f"Returning: {result}")

    return result

def critical_operation():
    """Example of critical logging"""
    try:
        connect_to_database()
    except Exception as e:
        # CRITICAL: System cannot continue
        logging.critical(f"Database connection failed: {e}")
        logging.critical("Application cannot continue without database")
        raise

# Usage
process_user_data(123)

Loggers, Handlers, and Formatters

For more control, use the three main components: Loggers (create messages), Handlers (send messages to destinations), and Formatters (format message appearance).

Creating a Named Logger

Instead of the root logger, create named loggers for different modules.

import logging

# Create a named logger
logger = logging.getLogger(__name__)  # Use module name
logger.setLevel(logging.DEBUG)

# Use the logger
logger.debug("Debug message")
logger.info("Info message")
logger.warning("Warning message")

# Best practice: Create logger at module level
# my_module.py
import logging

logger = logging.getLogger(__name__)

def my_function():
    logger.info("Function called")

# Output shows module name:
# INFO:my_module:Function called

# You can create hierarchical loggers
logger = logging.getLogger("myapp.database")
logger = logging.getLogger("myapp.api")
logger = logging.getLogger("myapp.api.users")

# Configure parent logger affects all children
app_logger = logging.getLogger("myapp")
app_logger.setLevel(logging.INFO)  # Applies to all myapp.* loggers

Handlers: Directing Output

Handlers determine where log messages go. You can add multiple handlers to one logger.

import logging

# Create logger
logger = logging.getLogger(__name__)
logger.setLevel(logging.DEBUG)

# Create console handler (logs to terminal)
console_handler = logging.StreamHandler()
console_handler.setLevel(logging.INFO)  # Only INFO and above to console

# Create file handler (logs to file)
file_handler = logging.FileHandler('app.log')
file_handler.setLevel(logging.DEBUG)  # All levels to file

# Add handlers to logger
logger.addHandler(console_handler)
logger.addHandler(file_handler)

# Now messages go to both places
logger.debug("This goes only to file")
logger.info("This goes to both console and file")
logger.error("This goes to both console and file")

# Common handlers:
# StreamHandler()           - Console output
# FileHandler(filename)     - Write to file
# RotatingFileHandler()     - Rotate files by size
# TimedRotatingFileHandler() - Rotate files by time
# SMTPHandler()             - Email logs
# SysLogHandler()           - System log
# HTTPHandler()             - Send logs to HTTP server

Formatters: Customizing Message Format

Formatters control how log messages appear.

import logging

# Create logger
logger = logging.getLogger(__name__)
logger.setLevel(logging.DEBUG)

# Create formatter
formatter = logging.Formatter(
    '%(asctime)s - %(name)s - %(levelname)s - %(message)s',
    datefmt='%Y-%m-%d %H:%M:%S'
)

# Create handler and set formatter
handler = logging.StreamHandler()
handler.setFormatter(formatter)
logger.addHandler(handler)

logger.info("Application started")
# Output:
# 2024-01-15 14:30:45 - __main__ - INFO - Application started

# Common format specifiers:
# %(asctime)s       - Human-readable time
# %(created)f       - Time as float
# %(levelname)s     - Log level (DEBUG, INFO, etc.)
# %(message)s       - The log message
# %(name)s          - Logger name
# %(filename)s      - Source filename
# %(lineno)d        - Line number
# %(funcName)s      - Function name
# %(process)d       - Process ID
# %(thread)d        - Thread ID

# Detailed formatter for debugging
detailed_formatter = logging.Formatter(
    '%(asctime)s [%(levelname)8s] %(name)s:%(lineno)d - %(message)s'
)

# Simple formatter for production
simple_formatter = logging.Formatter(
    '%(levelname)s: %(message)s'
)

Complete Example: Logger with Multiple Handlers

import logging

def setup_logger(name):
    """Set up a logger with both console and file handlers"""

    # Create logger
    logger = logging.getLogger(name)
    logger.setLevel(logging.DEBUG)

    # Prevent duplicate handlers
    if logger.handlers:
        return logger

    # Console handler with INFO level
    console_handler = logging.StreamHandler()
    console_handler.setLevel(logging.INFO)
    console_format = logging.Formatter(
        '%(levelname)s: %(message)s'
    )
    console_handler.setFormatter(console_format)

    # File handler with DEBUG level
    file_handler = logging.FileHandler('app.log')
    file_handler.setLevel(logging.DEBUG)
    file_format = logging.Formatter(
        '%(asctime)s - %(name)s - %(levelname)s - %(message)s'
    )
    file_handler.setFormatter(file_format)

    # Add handlers to logger
    logger.addHandler(console_handler)
    logger.addHandler(file_handler)

    return logger

# Use it
logger = setup_logger(__name__)

logger.debug("Detailed debug info")  # Only in file
logger.info("User logged in")        # Both console and file
logger.error("Failed to save data")  # Both console and file

# Console output:
# INFO: User logged in
# ERROR: Failed to save data

# File (app.log) output:
# 2024-01-15 14:30:45 - __main__ - DEBUG - Detailed debug info
# 2024-01-15 14:30:45 - __main__ - INFO - User logged in
# 2024-01-15 14:30:45 - __main__ - ERROR - Failed to save data

Logging to Files

File logging is essential for production applications. Learn to manage log files effectively.

Basic File Logging

import logging

# Simple file logging
logging.basicConfig(
    filename='app.log',
    filemode='a',  # 'a' = append, 'w' = overwrite
    level=logging.INFO,
    format='%(asctime)s - %(levelname)s - %(message)s'
)

logging.info("Application started")
logging.warning("Low memory warning")
logging.error("Failed to connect to API")

# The messages are written to app.log:
# 2024-01-15 14:30:45,123 - INFO - Application started
# 2024-01-15 14:30:46,456 - WARNING - Low memory warning
# 2024-01-15 14:30:47,789 - ERROR - Failed to connect to API

# Using FileHandler for more control
import logging

logger = logging.getLogger(__name__)
logger.setLevel(logging.DEBUG)

# Create file handler
file_handler = logging.FileHandler(
    'application.log',
    mode='a',
    encoding='utf-8'
)
file_handler.setLevel(logging.DEBUG)

# Add formatter
formatter = logging.Formatter(
    '%(asctime)s - %(name)s - %(levelname)s - %(message)s'
)
file_handler.setFormatter(formatter)

logger.addHandler(file_handler)

logger.info("Logging to file with custom handler")

Rotating Log Files

Prevent log files from growing indefinitely by using rotation.

import logging
from logging.handlers import RotatingFileHandler

# Rotate by file size
logger = logging.getLogger(__name__)
logger.setLevel(logging.DEBUG)

# Rotate when file reaches 1MB, keep 5 backup files
handler = RotatingFileHandler(
    'app.log',
    maxBytes=1024 * 1024,  # 1 MB
    backupCount=5
)

formatter = logging.Formatter(
    '%(asctime)s - %(name)s - %(levelname)s - %(message)s'
)
handler.setFormatter(formatter)
logger.addHandler(handler)

# Files created:
# app.log          (current file)
# app.log.1        (first backup)
# app.log.2        (second backup)
# app.log.3        (third backup)
# app.log.4        (fourth backup)
# app.log.5        (fifth backup)

# When app.log reaches 1MB:
# 1. app.log.5 is deleted
# 2. app.log.4 -> app.log.5
# 3. app.log.3 -> app.log.4
# 4. app.log.2 -> app.log.3
# 5. app.log.1 -> app.log.2
# 6. app.log -> app.log.1
# 7. New app.log is created

Time-Based Rotation

import logging
from logging.handlers import TimedRotatingFileHandler

logger = logging.getLogger(__name__)
logger.setLevel(logging.DEBUG)

# Rotate daily at midnight
handler = TimedRotatingFileHandler(
    'app.log',
    when='midnight',
    interval=1,
    backupCount=7  # Keep 7 days of logs
)

# Options for 'when':
# 'S'        - Seconds
# 'M'        - Minutes
# 'H'        - Hours
# 'D'        - Days
# 'midnight' - Roll over at midnight
# 'W0'-'W6'  - Roll over on specific weekday (0=Monday)

formatter = logging.Formatter(
    '%(asctime)s - %(name)s - %(levelname)s - %(message)s'
)
handler.setFormatter(formatter)
logger.addHandler(handler)

# Files created (example):
# app.log                    (current)
# app.log.2024-01-15        (yesterday's log)
# app.log.2024-01-14        (2 days ago)
# ... (up to 7 days)

# Rotate every hour, keep 24 hours
handler = TimedRotatingFileHandler(
    'app.log',
    when='H',
    interval=1,
    backupCount=24
)

Production-Ready File Logging Setup

import logging
from logging.handlers import RotatingFileHandler
import os

def setup_production_logging(app_name):
    """Configure production-ready logging"""

    # Create logs directory if it doesn't exist
    log_dir = 'logs'
    if not os.path.exists(log_dir):
        os.makedirs(log_dir)

    # Create logger
    logger = logging.getLogger(app_name)
    logger.setLevel(logging.DEBUG)

    # Prevent duplicate handlers
    if logger.handlers:
        return logger

    # Console handler - INFO and above
    console_handler = logging.StreamHandler()
    console_handler.setLevel(logging.INFO)
    console_format = logging.Formatter(
        '%(asctime)s [%(levelname)s] %(message)s',
        datefmt='%Y-%m-%d %H:%M:%S'
    )
    console_handler.setFormatter(console_format)

    # File handler - all levels, rotating
    file_handler = RotatingFileHandler(
        os.path.join(log_dir, f'{app_name}.log'),
        maxBytes=10 * 1024 * 1024,  # 10 MB
        backupCount=5
    )
    file_handler.setLevel(logging.DEBUG)
    file_format = logging.Formatter(
        '%(asctime)s - %(name)s - %(levelname)s - '
        '%(filename)s:%(lineno)d - %(message)s'
    )
    file_handler.setFormatter(file_format)

    # Error file handler - ERROR and above only
    error_handler = RotatingFileHandler(
        os.path.join(log_dir, f'{app_name}_errors.log'),
        maxBytes=5 * 1024 * 1024,  # 5 MB
        backupCount=3
    )
    error_handler.setLevel(logging.ERROR)
    error_handler.setFormatter(file_format)

    # Add all handlers
    logger.addHandler(console_handler)
    logger.addHandler(file_handler)
    logger.addHandler(error_handler)

    return logger

# Use it
logger = setup_production_logging('myapp')

logger.debug("Debug information")     # Only in myapp.log
logger.info("Application started")    # Console + myapp.log
logger.error("Database error")        # Console + both log files

# File structure created:
# logs/
#   myapp.log         (all logs)
#   myapp.log.1       (rotated backups)
#   ...
#   myapp_errors.log  (errors only)
#   myapp_errors.log.1

Best practice: Always log to files in production. Use separate files for different log levels (info vs errors) to make troubleshooting faster. Implement log rotation to prevent disk space issues.

Practical Logging Patterns

Real-world logging patterns for common scenarios.

Logging Exceptions

import logging

logger = logging.getLogger(__name__)

def divide(a, b):
    try:
        result = a / b
        logger.info(f"Division successful: {a} / {b} = {result}")
        return result
    except ZeroDivisionError:
        # Log exception with traceback
        logger.exception("Division by zero error")
        # OR use exc_info=True
        # logger.error("Division by zero error", exc_info=True)
        return None
    except Exception as e:
        # Log unexpected exceptions
        logger.exception(f"Unexpected error during division: {e}")
        raise

# Test it
result = divide(10, 0)

# Output includes full traceback:
# ERROR:__main__:Division by zero error
# Traceback (most recent call last):
#   File "script.py", line 7, in divide
#     result = a / b
# ZeroDivisionError: division by zero

# Best practice: Use logger.exception() in except blocks
# It automatically includes the traceback

Function Execution Logging

import logging
import time

logger = logging.getLogger(__name__)

def process_data(data):
    """Process data with logging"""

    # Log function entry
    logger.info(f"Starting process_data with {len(data)} items")
    start_time = time.time()

    try:
        # Log progress
        for i, item in enumerate(data):
            logger.debug(f"Processing item {i + 1}/{len(data)}: {item}")

            # Simulate processing
            process_item(item)

            # Log milestones
            if (i + 1) % 100 == 0:
                logger.info(f"Processed {i + 1} items so far...")

        # Log success
        elapsed = time.time() - start_time
        logger.info(
            f"Successfully processed {len(data)} items "
            f"in {elapsed:.2f} seconds"
        )

    except Exception as e:
        logger.exception(f"Failed to process data: {e}")
        raise

    finally:
        logger.debug("Exiting process_data")

# Create a decorator for automatic logging
import functools

def log_execution(logger):
    """Decorator to log function execution"""
    def decorator(func):
        @functools.wraps(func)
        def wrapper(*args, **kwargs):
            logger.debug(f"Calling {func.__name__}()")
            try:
                result = func(*args, **kwargs)
                logger.debug(f"{func.__name__}() completed successfully")
                return result
            except Exception as e:
                logger.exception(f"{func.__name__}() raised exception: {e}")
                raise
        return wrapper
    return decorator

# Use the decorator
@log_execution(logger)
def calculate_total(items):
    return sum(items)

result = calculate_total([1, 2, 3, 4, 5])
# DEBUG:__main__:Calling calculate_total()
# DEBUG:__main__:calculate_total() completed successfully

Structured Logging with Extra Data

import logging

logger = logging.getLogger(__name__)

# Add extra context to log messages
def process_user_request(user_id, action):
    # Pass extra data with 'extra' parameter
    logger.info(
        f"Processing request",
        extra={
            'user_id': user_id,
            'action': action,
            'request_id': generate_request_id()
        }
    )

# Create custom formatter to include extra fields
class StructuredFormatter(logging.Formatter):
    def format(self, record):
        # Add custom fields if they exist
        if hasattr(record, 'user_id'):
            record.msg = f"[User: {record.user_id}] {record.msg}"
        if hasattr(record, 'request_id'):
            record.msg = f"[Request: {record.request_id}] {record.msg}"
        return super().format(record)

# Use it
handler = logging.StreamHandler()
formatter = StructuredFormatter(
    '%(asctime)s - %(levelname)s - %(message)s'
)
handler.setFormatter(formatter)
logger.addHandler(handler)

# Example: User context throughout request
class RequestContext:
    def __init__(self, user_id, request_id):
        self.user_id = user_id
        self.request_id = request_id

    def log(self, level, message):
        logger.log(
            level,
            message,
            extra={
                'user_id': self.user_id,
                'request_id': self.request_id
            }
        )

# Use it
context = RequestContext(user_id=123, request_id='abc-456')
context.log(logging.INFO, "Processing payment")
context.log(logging.ERROR, "Payment failed")

# Output:
# 2024-01-15 14:30:45 - INFO - [Request: abc-456] [User: 123] Processing payment
# 2024-01-15 14:30:46 - ERROR - [Request: abc-456] [User: 123] Payment failed

Configuration from File

# logging_config.ini
[loggers]
keys=root,myapp

[handlers]
keys=consoleHandler,fileHandler

[formatters]
keys=simpleFormatter,detailedFormatter

[logger_root]
level=INFO
handlers=consoleHandler

[logger_myapp]
level=DEBUG
handlers=consoleHandler,fileHandler
qualname=myapp
propagate=0

[handler_consoleHandler]
class=StreamHandler
level=INFO
formatter=simpleFormatter
args=(sys.stdout,)

[handler_fileHandler]
class=FileHandler
level=DEBUG
formatter=detailedFormatter
args=('app.log', 'a')

[formatter_simpleFormatter]
format=%(levelname)s: %(message)s

[formatter_detailedFormatter]
format=%(asctime)s - %(name)s - %(levelname)s - %(message)s
datefmt=%Y-%m-%d %H:%M:%S

# Load the configuration
import logging.config

logging.config.fileConfig('logging_config.ini')

logger = logging.getLogger('myapp')
logger.info("Logging configured from file")

# Or use dictionary configuration (more flexible)
import logging.config

config = {
    'version': 1,
    'disable_existing_loggers': False,
    'formatters': {
        'simple': {
            'format': '%(levelname)s: %(message)s'
        },
        'detailed': {
            'format': '%(asctime)s - %(name)s - %(levelname)s - %(message)s'
        }
    },
    'handlers': {
        'console': {
            'class': 'logging.StreamHandler',
            'level': 'INFO',
            'formatter': 'simple',
            'stream': 'ext://sys.stdout'
        },
        'file': {
            'class': 'logging.handlers.RotatingFileHandler',
            'level': 'DEBUG',
            'formatter': 'detailed',
            'filename': 'app.log',
            'maxBytes': 10485760,  # 10MB
            'backupCount': 5
        }
    },
    'loggers': {
        'myapp': {
            'level': 'DEBUG',
            'handlers': ['console', 'file'],
            'propagate': False
        }
    }
}

logging.config.dictConfig(config)
logger = logging.getLogger('myapp')

Logging Best Practices

✓ Do This

Use named loggers (__name__)
Choose appropriate log levels
Log exceptions with .exception()
Use structured logging (extra context)
Configure logging once at startup
Rotate log files in production
Include timestamps and levels
Log function entry/exit for complex flows

✗ Avoid This

Don't use print() in production code
Don't log sensitive data (passwords, tokens)
Don't log in tight loops without throttling
Don't use DEBUG level in production
Don't forget to rotate log files
Don't log entire large objects
Don't call basicConfig() multiple times
Don't mix logging and print statements

Key Takeaways

Logging Basics

Use logging module, not print()
Five levels: DEBUG, INFO, WARNING, ERROR, CRITICAL
Configure once with basicConfig()
Messages filter by configured level
Use logger.exception() for errors

Components

Loggers: Create log messages
Handlers: Send to destinations
Formatters: Format appearance
Use named loggers: getLogger(__name__)
Multiple handlers for multiple outputs

File Logging

Use FileHandler for basic file logging
RotatingFileHandler rotates by size
TimedRotatingFileHandler rotates by time
Keep separate error logs
Always rotate in production

Production Tips

Set level to INFO or WARNING
Log to files, not just console
Include context (user IDs, request IDs)
Never log sensitive data
Monitor log files for errors

What's Next?

You've mastered professional logging! Now let's learn how to create custom exceptions and build robust error handling systems for production applications.

Custom Exceptions - Create meaningful exception classes for your application
Exception Hierarchies - Build organized exception structures for better error handling
Context Managers - Master the with statement and exception handling patterns

Back to "Data Structures"

Python IntermediateLesson 12

Next: "Error Handling & Custom Exceptions"