Professional Logging

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")

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")

# IMPORTANT: basicConfig() only configures the root logger the FIRST time it
# runs. Once a handler exists it returns silently, so the call below has no
# effect at all: no file is created, no error is raised, and the two messages
# after it still go to the console in the format set above.
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 was meant for app.log")
logging.error("So was this")

# If you genuinely need to reconfigure inside one program, pass force=True
# (Python 3.8+), which closes and replaces the existing handlers:
logging.basicConfig(level=logging.DEBUG, filename='app.log', force=True)
logging.info("This one really is written to app.log")

print("--- app.log ---")
print(open('app.log').read(), end='')

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)

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

import logging

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

# Stand-ins for the real data layer
USERS = {123: {"name": "Alice", "email": None}}

def get_user(user_id):
    return USERS.get(user_id)

def do_processing(user):
    return {"name": user["name"].upper()}

def connect_to_database():
    raise ConnectionError("could not reach db:5432")

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

    # DEBUG: Detailed diagnostic information
    logging.debug("Entering process_user_data(user_id=%s)", user_id)

    # INFO: Confirmation that things are working
    logging.info("Processing user %s", user_id)

    user = get_user(user_id)

    if user is None:
        # ERROR: Failed to complete operation
        logging.error("User %s not found", user_id)
        return None

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

    # DEBUG: Show intermediate values
    logging.debug("User data: %s", user)

    result = do_processing(user)

    # INFO: Operation completed successfully
    logging.info("Successfully processed user %s", user_id)

    # DEBUG: Show return value
    logging.debug("Returning: %s", result)

    return result

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

# Usage
process_user_data(123)
process_user_data(999)

try:
    critical_operation()
except ConnectionError:
    pass

import logging

# A logger level alone is not enough: with no handler anywhere in the chain
# Python falls back to logging.lastResort, which only emits WARNING and above
# and prints the bare message. basicConfig() installs a real handler.
logging.basicConfig(level=logging.DEBUG, format='%(levelname)s:%(name)s:%(message)s')

# 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: one logger per module, named after the module. Running this
# file directly makes __name__ "__main__"; imported as my_module it would be
# "my_module", and the name appears in every line that logger emits.
module_logger = logging.getLogger("my_module")
module_logger.info("Function called")

# Hierarchical loggers: a dot in the name creates a parent/child relationship
db_logger = logging.getLogger("myapp.database")
api_logger = logging.getLogger("myapp.api")
users_logger = logging.getLogger("myapp.api.users")

# Configuring the parent affects every child that has no level of its own
app_logger = logging.getLogger("myapp")
app_logger.setLevel(logging.INFO)  # Applies to all myapp.* loggers

db_logger.debug("Connection pool details")   # Dropped: DEBUG < INFO
api_logger.info("Request received")
users_logger.warning("Unknown field in payload")

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. Neither handler has a formatter, so both
# print the bare message.
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")

print("--- app.log ---")
print(open('app.log').read(), end='')

# 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

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")

# 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: %(levelname)8s right-aligns in 8 columns
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'
)

# Swap the formatter to see the difference on the same logger
handler.setFormatter(detailed_formatter)
logger.warning("Detailed format")
handler.setFormatter(simple_formatter)
logger.warning("Simple format")

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

# %(asctime)s with no datefmt keeps the milliseconds after the comma
print("--- app.log ---")
print(open('app.log').read(), end='')

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")

# Using FileHandler for more control
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)

# This record reaches application.log through the handler above, and ALSO
# app.log, because records propagate up to the root logger that basicConfig
# configured. Set logger.propagate = False to keep it out of the root's file.
logger.info("Logging to file with custom handler")

for name in ('app.log', 'application.log'):
    print(f"--- {name} ---")
    print(open(name).read(), end='')

import logging
import os
from logging.handlers import RotatingFileHandler

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

# In production this would be maxBytes=1024 * 1024 (1 MB). It is 1 KB here so
# the demo below actually rolls over instead of writing one small file.
handler = RotatingFileHandler(
    'app.log',
    maxBytes=1024,     # 1 KB
    backupCount=5      # keep app.log.1 through app.log.5
)

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

for i in range(1, 101):
    logger.info("Log record number %s", i)

print("Files on disk:", sorted(f for f in os.listdir('.') if f.startswith('app.log')))

# When app.log reaches maxBytes:
# 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

import logging
import os
import time
from logging.handlers import TimedRotatingFileHandler

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

# Production setting: when='midnight', interval=1, backupCount=7 keeps a week
# of daily files. This demo rolls every second so it finishes in a few seconds.
handler = TimedRotatingFileHandler(
    'app.log',
    when='S',
    interval=1,
    backupCount=3
)

# 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)

for i in range(1, 4):
    logger.info("Record written in interval %s", i)
    time.sleep(1.1)

# The rolled files carry the rollover time as a suffix
for name in sorted(f for f in os.listdir('.') if f.startswith('app.log')):
    print(name)

# Save as myapp.py, then run: python myapp.py
import logging
import os
from logging.handlers import RotatingFileHandler

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

# Backups (myapp.log.1 and so on) only appear once a file passes maxBytes
for name in sorted(os.listdir('logs')):
    print(f"--- logs/{name} ---")
    print(open(os.path.join('logs', name)).read(), end='')

# Save as divide_demo.py, then run: python divide_demo.py
import logging

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

def divide(a, b):
    try:
        result = a / b
        logger.info("Division successful: %s / %s = %s", 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:
        # Log unexpected exceptions
        logger.exception("Unexpected error during division")
        raise

# Test it
divide(10, 2)
divide(10, 0)

# Best practice: Use logger.exception() in except blocks. It logs at ERROR
# level and attaches the active traceback automatically.

import functools
import logging
import time

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

def process_item(item):
    return item * 2

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

    # Log function entry
    logger.info("Starting process_data with %s items", len(data))
    start_time = time.time()

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

            process_item(item)

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

        # Log success
        elapsed = time.time() - start_time
        logger.info(
            "Successfully processed %s items in %.2f seconds", len(data), elapsed
        )

    except Exception:
        logger.exception("Failed to process data")
        raise

    finally:
        logger.debug("Exiting process_data")

process_data([10, 20, 30])

# Create a decorator for automatic logging
def log_execution(logger):
    """Decorator to log function execution"""
    def decorator(func):
        @functools.wraps(func)
        def wrapper(*args, **kwargs):
            logger.debug("Calling %s()", func.__name__)
            try:
                result = func(*args, **kwargs)
                logger.debug("%s() completed successfully", func.__name__)
                return result
            except Exception:
                logger.exception("%s() raised exception", func.__name__)
                raise
        return wrapper
    return decorator

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

calculate_total([1, 2, 3, 4, 5])

import logging
from uuid import uuid4

logger = logging.getLogger(__name__)


def generate_request_id():
    return str(uuid4())


# Add extra context to log messages
def process_user_request(user_id, action):
    # Pass extra data with the 'extra' parameter
    logger.info(
        "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)

# Without this the logger inherits the root level (WARNING) and the INFO
# calls below are silently dropped, no matter what the handler allows.
logger.setLevel(logging.INFO)

# 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
            }
        )

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

# The request id here is a fresh uuid4, so it differs on every run
process_user_request(user_id=456, action='checkout')

import logging.config

# Reads the [loggers] / [handlers] / [formatters] sections shown above
logging.config.fileConfig('logging_config.ini')

logger = logging.getLogger('myapp')
logger.info("Logging configured from file")
logger.debug("Only the file handler is at DEBUG, so this line is file-only")

print("--- app.log ---")
print(open('app.log').read(), end='')

import logging.config

# dictConfig is the more flexible option: the same structure as the ini file,
# expressed as a dict you can build at runtime
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')

logger.info("Configured from a dict")
logger.debug("File handler only")

print("--- app.log ---")
print(open('app.log').read(), end='')