Python Logging — Production-Ready Logging

The logging module provides flexible event logging for applications and libraries. Proper logging is essential for debugging, monitoring, and auditing production systems. This module is part of Python's standard library and is highly configurable.

Learning Objectives

• Configure logging with basicConfig and custom setups
• Create custom loggers with handlers and formatters
• Implement structured logging for production systems
• Use RotatingFileHandler and SysLogHandler
• Build logging for web applications
• Apply logging best practices and avoid common mistakes

Why Not Just Use Print?

# print() problems:
print("Starting process")           # No timestamp
print("Error: file not found")      # No severity level
print(f"User {user_id} logged in")  # No way to filter

# logging solves all of these:
logging.info("Starting process")
logging.error("Error: file not found")
logging.info(f"User {user_id} logged in")

Log Levels Explained

Level       Numerical Value  When to Use
-----       ---------------  ------------------------------------------
DEBUG             10         Detailed info for developers (loop vars, API responses)
INFO              20         Confirmation that things are working (startup, requests)
WARNING           30         Something unexpected but not broken (disk 90% full)
ERROR             40         Something broke (failed to connect, exception)
CRITICAL          50         Program may stop (database down, out of memory)

The hierarchy is: DEBUG < INFO < WARNING < ERROR < CRITICAL. When you set a level, all messages at that level and above are processed.

Basic Configuration

import logging

# Simple setup — good for development
logging.basicConfig(
    level=logging.INFO,
    format='%(asctime)s - %(name)s - %(levelname)s - %(message)s',
    datefmt='%Y-%m-%d %H:%M:%S'
)

# Create logger
logger = logging.getLogger(__name__)

# Log at different levels
logger.debug("Debug message")      # Not shown (below INFO)
logger.info("Info message")        # Shown
logger.warning("Warning message")  # Shown
logger.error("Error message")      # Shown
logger.critical("Critical message") # Shown

Format Variables Reference

Custom Logger with Handlers

Handlers determine where log messages go. You can attach multiple handlers to a single logger.

import logging
from logging.handlers import RotatingFileHandler

def setup_logger(name):
    logger = logging.getLogger(name)
    logger.setLevel(logging.DEBUG)

    # Console handler — show INFO and above
    console = logging.StreamHandler()
    console.setLevel(logging.INFO)
    console_fmt = logging.Formatter(
        '%(asctime)s - %(levelname)s - %(message)s',
        datefmt='%H:%M:%S'
    )
    console.setFormatter(console_fmt)

    # File handler — record DEBUG and above
    file_handler = RotatingFileHandler(
        f'{name}.log',
        maxBytes=5*1024*1024,  # 5MB per file
        backupCount=5           # Keep 5 backups
    )
    file_handler.setLevel(logging.DEBUG)
    file_fmt = logging.Formatter(
        '%(asctime)s - %(name)s - %(levelname)s - %(funcName)s:%(lineno)d - %(message)s'
    )
    file_handler.setFormatter(file_fmt)

    logger.addHandler(console)
    logger.addHandler(file_handler)

    return logger

# Usage
logger = setup_logger("myapp")
logger.info("Application started")
logger.debug("Loading configuration from %s", "config.json")
logger.error("Failed to connect to database: %s", "Connection refused")

RotatingFileHandler Deep Dive

RotatingFileHandler prevents log files from growing unbounded by rotating them when they reach a size limit.

from logging.handlers import RotatingFileHandler, TimedRotatingFileHandler

# Size-based rotation: rotate when file reaches 10MB
handler = RotatingFileHandler(
    'app.log',
    maxBytes=10*1024*1024,  # 10MB
    backupCount=10           # Keep 10 old files
)

# Time-based rotation: rotate daily at midnight
handler = TimedRotatingFileHandler(
    'app.log',
    when='midnight',        # Rotate at midnight
    interval=1,             # Every 1 day
    backupCount=30          # Keep 30 days
)

# Time-based rotation: rotate every hour
handler = TimedRotatingFileHandler(
    'app.log',
    when='h',               # Every hour
    interval=1,
    backupCount=168         # Keep 7 days of hourly logs
)

# Rotation naming:
# app.log (current)
# app.log.2024-01-15 (rotated yesterday)
# app.log.2024-01-14 (two days ago)

SysLogHandler for System Logging

import logging
from logging.handlers import SysLogHandler

# Local syslog
handler = SysLogHandler(address='/dev/log')

# Remote syslog server
handler = SysLogHandler(address=('logserver.example.com', 514))

# Custom format for syslog
formatter = logging.Formatter(
    'myapp: %(levelname)s - %(message)s'
)
handler.setFormatter(formatter)

logger = logging.getLogger('syslog')
logger.addHandler(handler)
logger.setLevel(logging.INFO)

logger.info("User authentication successful")
logger.error("Database connection failed")

Structured Logging (JSON)

Structured logs are machine-readable, making them easy to search and analyze in log aggregation tools (ELK, Datadog, CloudWatch, Splunk).

import logging
import json
from datetime import datetime

class JSONFormatter(logging.Formatter):
    def format(self, record):
        log_entry = {
            "timestamp": datetime.utcnow().isoformat(),
            "level": record.levelname,
            "logger": record.name,
            "message": record.getMessage(),
            "module": record.module,
            "function": record.funcName,
            "line": record.lineno,
        }
        if record.exc_info:
            log_entry["exception"] = self.formatException(record.exc_info)
        return json.dumps(log_entry)

# Setup structured logger
logger = logging.getLogger("api")
handler = logging.StreamHandler()
handler.setFormatter(JSONFormatter())
logger.addHandler(handler)

# Usage
logger.info("User logged in", extra={"user_id": 123, "ip": "192.168.1.1"})
# Output: {"timestamp": "2024-01-15T10:30:00", "level": "INFO", "message": "User logged in", ...}

Advanced JSON Formatter with Custom Fields

import logging
import json
from datetime import datetime
from typing import Any

class AdvancedJSONFormatter(logging.Formatter):
    def __init__(self, extra_fields: dict = None):
        self.extra_fields = extra_fields or {}

    def format(self, record: logging.LogRecord) -> str:
        log_entry: dict[str, Any] = {
            "timestamp": datetime.utcnow().isoformat() + "Z",
            "level": record.levelname,
            "logger": record.name,
            "message": record.getMessage(),
            "module": record.module,
            "function": record.funcName,
            "line": record.lineno,
            "process": record.process,
            "thread": record.thread,
        }

        # Add extra fields from logger
        for key in ["user_id", "request_id", "trace_id", "span_id"]:
            val = getattr(record, key, None)
            if val is not None:
                log_entry[key] = val

        # Add exception info
        if record.exc_info and record.exc_info[0] is not None:
            log_entry["exception"] = {
                "type": record.exc_info[0].__name__,
                "message": str(record.exc_info[1]),
                "traceback": self.formatException(record.exc_info),
            }

        # Add any static extra fields
        log_entry.update(self.extra_fields)

        return json.dumps(log_entry, default=str)

# Usage
logger = logging.getLogger("api")
handler = logging.StreamHandler()
handler.setFormatter(AdvancedJSONFormatter(extra_fields={"service": "user-api", "version": "1.0.0"}))
logger.addHandler(handler)
logger.setLevel(logging.INFO)

logger.info("Request processed", extra={"request_id": "abc-123", "user_id": 42})

Context Managers for Logging

import logging
import time
from contextlib import contextmanager

@contextmanager
def log_operation(logger, operation_name):
    """Log the start, duration, and result of an operation."""
    logger.info(f"Starting: {operation_name}")
    start = time.perf_counter()
    try:
        yield
        duration = time.perf_counter() - start
        logger.info(f"Completed: {operation_name} ({duration:.2f}s)")
    except Exception as e:
        duration = time.perf_counter() - start
        logger.error(f"Failed: {operation_name} ({duration:.2f}s) - {e}")
        raise

# Usage
logger = setup_logger("myapp")
with log_operation(logger, "data import"):
    import_data()  # Your operation here

Logging Configuration with Dict Config

import logging.config

LOGGING_CONFIG = {
    'version': 1,
    'disable_existing_loggers': False,
    'formatters': {
        'standard': {
            'format': '%(asctime)s [%(levelname)s] %(name)s: %(message)s'
        },
        'json': {
            'class': 'myapp.logging.JSONFormatter',
        },
    },
    'handlers': {
        'console': {
            'class': 'logging.StreamHandler',
            'level': 'INFO',
            'formatter': 'standard',
            'stream': 'ext://sys.stdout',
        },
        'file': {
            'class': 'logging.handlers.RotatingFileHandler',
            'level': 'DEBUG',
            'formatter': 'json',
            'filename': 'app.log',
            'maxBytes': 10485760,  # 10MB
            'backupCount': 5,
        },
        'error_file': {
            'class': 'logging.handlers.RotatingFileHandler',
            'level': 'ERROR',
            'formatter': 'json',
            'filename': 'errors.log',
            'maxBytes': 10485760,
            'backupCount': 5,
        },
    },
    'loggers': {
        '': {  # Root logger
            'level': 'DEBUG',
            'handlers': ['console', 'file', 'error_file'],
        },
        'myapp': {
            'level': 'DEBUG',
            'propagate': False,
        },
        'uvicorn': {
            'level': 'WARNING',
            'propagate': False,
        },
    },
}

logging.config.dictConfig(LOGGING_CONFIG)

Web Application Logging Example

import logging
import logging.config
from fastapi import FastAPI, Request
from datetime import datetime
import time
import uuid

# Setup logging
logging.config.dictConfig({
    'version': 1,
    'disable_existing_loggers': False,
    'formatters': {
        'json': {
            'format': '%(message)s',
        },
    },
    'handlers': {
        'console': {
            'class': 'logging.StreamHandler',
            'formatter': 'json',
        },
    },
    'loggers': {
        'app': {
            'level': 'INFO',
            'handlers': ['console'],
        },
    },
})

app_logger = logging.getLogger('app')
app = FastAPI()

@app.middleware("http")
async def log_requests(request: Request, call_next):
    request_id = str(uuid.uuid4())
    start = time.time()

    # Log request
    app_logger.info("Request started", extra={
        "request_id": request_id,
        "method": request.method,
        "url": str(request.url),
        "client_ip": request.client.host,
    })

    response = await call_next(request)

    # Log response
    duration = time.time() - start
    app_logger.info("Request completed", extra={
        "request_id": request_id,
        "method": request.method,
        "url": str(request.url),
        "status_code": response.status_code,
        "duration_ms": round(duration * 1000, 2),
    })

    return response

@app.get("/users/{user_id}")
def get_user(user_id: int):
    app_logger.info("Fetching user", extra={"user_id": user_id})
    # Business logic here
    return {"user_id": user_id}

Common Mistakes

Bad vs Good Logging

# BAD: f-string always evaluated
logger.info(f"Processing user {expensive_function()}")

# GOOD: Lazy evaluation with % formatting
logger.info("Processing user %s", expensive_function())

# BAD: Logging sensitive data
logger.info(f"User password: {password}")

# GOOD: Sanitized logging
logger.info(f"User login attempt for: {username}")

# BAD: No exception context
except Exception as e:
    logger.error("Something went wrong")

# GOOD: Full exception context
except Exception as e:
    logger.error("Something went wrong", exc_info=True)

Best Practices

1. Use getLogger(__name__) — Creates a hierarchical logger matching your module structure
2. Set appropriate levels — DEBUG in dev, INFO in production, WARNING for third-party libraries
3. Use structured logging (JSON) — Enables searching and filtering in log aggregators
4. Configure handlers for console, file, and external services — Different outputs for different needs
5. Use RotatingFileHandler — Prevents huge log files from filling disk
6. Include context — Add request_id, user_id, trace_id for distributed tracing
7. Never log sensitive data — Passwords, tokens, PII, credit cards
8. Use %s formatting — Lazy evaluation prevents unnecessary string formatting
9. Add exc_info=True — Always include tracebacks in error logs
10. Test your logging — Verify logs appear in expected format and destination

Key Takeaways

1. Use getLogger(__name__) for module-level loggers
2. Set appropriate levels for different environments
3. Use structured logging (JSON) for production
4. Configure handlers for console, file, and external services
5. Use RotatingFileHandler to prevent huge log files
6. Include function name and line number in file logs
7. Never log sensitive data (passwords, tokens, PII)
8. Logging is better than print for production code
9. Use %s string formatting for lazy evaluation
10. Always include exception tracebacks with exc_info=True