Logging, Diagnostics, and Observability

Introduction

A running program communicates with its operators through evidence. When an application behaves incorrectly, developers need more than a vague message such as “request failed.” They need to know what happened, when it happened, which component was involved, how serious the event was, and whether the system recovered. Logging provides this evidence. Diagnostics use it, together with exceptions, metrics, traces, and system state, to explain faults and support decisions.

Python’s logging package supplies a standard, extensible framework for recording application events. It supports severity levels, hierarchical loggers, handlers, formatters, filters, exception tracebacks, and file rotation. Used well, logging improves reliability and maintainability. Used poorly, it can expose sensitive information, overwhelm storage, hide failures, or create false confidence.

This chapter develops a practical model for structured and configurable logging. It also distinguishes ordinary operational records from exceptions and introduces observability as a broader discipline.

Learning Objectives

By the end of this chapter, you should be able to:

• explain the purpose of logs, exceptions, metrics, traces, and diagnostics;
• select appropriate Python logging levels;
• configure loggers, handlers, formatters, and filters;
• produce structured and machine-readable log records;
• preserve useful traceback information;
• implement size-based and time-based log rotation;
• avoid common logging security and performance failures; and
• use diagnostic evidence to make operational decisions.

1. Logs, Exceptions, and Observability

A log record is a time-stamped account of an event. Examples include a user authentication attempt, a completed database query, or a configuration reload. A log does not necessarily mean that something failed.

An exception is an object representing an abnormal condition detected during execution. It may be caught and handled, propagated to a caller, or terminate a program. An exception explains a control-flow event; a log records information for later inspection. They are related but not identical. An exception can be handled without being logged, and a log can describe normal operation without an exception.

Diagnostics is the systematic collection and interpretation of evidence about program behaviour. Observability is the extent to which the internal state of a system can be inferred from its external outputs. In modern systems, observability commonly combines:

• Logs: discrete event records;
• Metrics: numerical measurements aggregated over time, such as request rate or error percentage;
• Traces: causal paths of a request across services and components; and
• Profiles and dumps: evidence about resource usage, memory, threads, or process state.

Logging is therefore one part of observability, not a complete substitute for it.

2. The Python Logging Model

A logging call creates a LogRecord. The record contains fields such as logger name, level, message, timestamp, source file, line number, and exception information. The record is passed through a hierarchy of loggers and, if enabled, to one or more handlers.

The principal objects are:

Loggers are named hierarchically. A logger named shop.payment is conceptually a child of shop. The root logger is the ultimate ancestor. A library should normally create a module-level logger:

import logging

logger = logging.getLogger(__name__)

Using __name__ allows an application to configure groups of modules without modifying library code.

Severity Levels

Python’s standard levels, from least to most severe, are:

A logger configured at INFO normally discards DEBUG records. This is a threshold, not a ranking of whether a message is morally or technically important. A warning is not automatically an exception, and an error message does not necessarily terminate the process.

Use lazy formatting for potentially expensive values:

logger.debug("Loaded %d records", len(records))

This allows logging to defer interpolation when the level is disabled. Do not use logging as a substitute for validation, user feedback, or exception handling.

3. Configuration, Handlers, and Formatters

A logger decides whether a record is enabled; a handler decides where it goes. A single record can be sent to multiple handlers—for example, informational records to the console and warnings or errors to a file.

A simple application configuration is:

import logging
import sys

logger = logging.getLogger("inventory")
logger.setLevel(logging.DEBUG)

console = logging.StreamHandler(sys.stdout)
console.setLevel(logging.INFO)
console.setFormatter(logging.Formatter(
    "%(asctime)s %(levelname)s %(name)s %(message)s"
))

logger.addHandler(console)

The logger’s level and the handler’s level both matter. A record must pass the logger’s effective level and the relevant handler’s level. A common error is setting a handler to INFO and expecting DEBUG records to appear; the handler will still discard them.

Propagation and Duplicate Records

By default, a child logger propagates records to ancestor handlers. If both a child and the root logger have equivalent handlers, one event may be printed twice. Applications should generally configure handlers at one deliberate point, often the application entry point, and allow module loggers to propagate.

Set logger.propagate = False only when a logger is intentionally managed independently. Libraries should avoid configuring global handlers because doing so interferes with the host application.

Configuration with dictConfig

For deployable applications, configuration should be separated from business logic. logging.config.dictConfig supports explicit, readable configuration:

import logging.config

LOGGING = {
    "version": 1,
    "disable_existing_loggers": False,
    "formatters": {
        "standard": {
            "format": "%(asctime)s %(levelname)s %(name)s %(message)s"
        }
    },
    "handlers": {
        "console": {
            "class": "logging.StreamHandler",
            "level": "INFO",
            "formatter": "standard",
            "stream": "ext://sys.stdout"
        }
    },
    "root": {
        "level": "INFO",
        "handlers": ["console"]
    }
}

logging.config.dictConfig(LOGGING)

disable_existing_loggers=False is often appropriate when third-party libraries should continue to emit records. Configuration must still be reviewed because a dependency may generate excessive output.

4. Structured Logging

A plain message is convenient for people but difficult for machines to search reliably. Structured logging stores event data as named fields. For example, instead of:

Payment failed for order 8142 after 3 retries

an event can contain event, order_id, and attempts as separate fields. Structured records support filtering, dashboards, alert rules, and correlation.

Python’s standard formatter is text-oriented, but a custom formatter can serialize selected fields as JSON. A minimal implementation is:

import json
import logging

class JsonFormatter(logging.Formatter):
    def format(self, record):
        event = {
            "time": self.formatTime(record, self.datefmt),
            "level": record.levelname,
            "logger": record.name,
            "message": record.getMessage(),
        }
        for field in ("request_id", "user_id", "order_id"):
            if hasattr(record, field):
                event[field] = getattr(record, field)
        if record.exc_info:
            event["exception"] = self.formatException(record.exc_info)
        return json.dumps(event, ensure_ascii=False)

Additional fields can be supplied with extra:

logger.info(
    "Order accepted",
    extra={"request_id": request_id, "order_id": order_id}
)

Every key supplied through extra must not conflict with built-in LogRecord attributes. In larger systems, a LoggerAdapter, filter, or context variable can attach correlation fields consistently.

Structured logging should use stable event names and field meanings. A field named duration_ms should always represent milliseconds, not a mixture of seconds and milliseconds. Avoid putting an entire arbitrary object into a record: it may be difficult to serialize, expensive to compute, or unsafe to disclose.

5. Exceptions and Tracebacks

When an operation fails, code should decide whether it can recover, translate the exception, retry, or allow it to propagate. Logging should normally occur at the boundary where the failure is handled or where it becomes operationally significant. Logging and re-raising at every stack level often produces duplicate records.

Use logger.exception() inside an active except block. It logs at ERROR level and includes the current traceback:

try:
    result = parse_config(path)
except ValueError:
    logger.exception("Configuration is invalid", extra={"path": path})
    raise

Equivalent explicit code is:

logger.error("Configuration is invalid", exc_info=True)

A traceback identifies the call path and source location. It is essential for debugging, but it can reveal file paths, query text, tokens, or user data. Production systems should control access to logs and avoid logging secrets. Never log passwords, private keys, session tokens, or full payment-card data.

Exception chaining preserves causality:

try:
    data = read_file(path)
except OSError as exc:
    raise ConfigurationError(f"Cannot read {path}") from exc

The new exception communicates domain meaning while from exc retains the original cause. A broad except Exception should be used only at a deliberate boundary, such as a worker supervisor or request handler, where the program can record the failure and return a safe response.

6. Rotation, Retention, and Storage

A log file that grows without limit can exhaust disk space and stop an application or the operating system. Rotation limits growth by creating a new file according to size or time.

Size-Based Rotation

from logging.handlers import RotatingFileHandler

handler = RotatingFileHandler(
    "app.log",
    maxBytes=10_000_000,
    backupCount=5,
    encoding="utf-8"
)

Here, maxBytes is the approximate threshold for rotation and backupCount is the number of backup files retained. The total storage is approximately bounded by the active file plus the backups, although exact size depends on record boundaries and implementation timing.

Time-Based Rotation

from logging.handlers import TimedRotatingFileHandler

handler = TimedRotatingFileHandler(
    "app.log",
    when="midnight",
    interval=1,
    backupCount=14,
    encoding="utf-8",
    utc=True
)

Time zones, daylight-saving changes, external log collectors, and multiple processes must be considered. In containerized deployments, writing to standard output and allowing the platform to collect and rotate logs is often preferable. A standard file handler is not automatically safe for concurrent writes from multiple processes; specialized handlers or an external collector may be required.

Retention is a governance decision as well as a technical one. Keep enough information for incident investigation and legal or operational requirements, but no more than necessary. Define access controls, backup policy, deletion rules, and the treatment of personal data.

7. Diagnostics and Operational Decision-Making

Logs become useful evidence when they support a question and a decision. A practical diagnostic process is:

1. Define the symptom: for example, elevated request failures.
2. Establish a time window: compare the affected period with a normal baseline.
3. Correlate events: use request IDs, job IDs, host names, and service names.
4. Separate symptoms from causes: repeated timeout messages may reflect a database outage rather than an application defect.
5. Test competing explanations: compare error rates, latency, resource usage, and deployment times.
6. Choose an action: rollback, scale, repair configuration, disable a feature, or continue monitoring.
7. Record the result: verify whether the action changed the evidence.

Useful records usually include timestamp, severity, component, event name, outcome, correlation identifier, and relevant bounded values. A log message should answer as many of these questions as practical: What happened? Where? When? To which operation? With what result?

Logs should not be treated as perfectly complete. Sampling, dropped records, clock differences, asynchronous queues, and process crashes can create gaps. A missing record is not proof that an event did not occur. Metrics are often better for rates and trends; traces are better for following one request across components.

Example Diagnostic Reasoning

Suppose a service reports a rise in ERROR records containing database timeout. A responsible conclusion requires more evidence. If request latency and database connection usage rose simultaneously after a deployment, a connection-pool regression is plausible. If only one geographic region is affected and network latency increased, a regional connectivity problem is more plausible. The log message identifies a symptom; correlated evidence supports the decision.

8. A Complete Example

The following illustrative program configures a rotating file, a console handler, structured fields, and traceback logging:

import logging
from logging.handlers import RotatingFileHandler


def configure_logging():
    logger = logging.getLogger("billing")
    logger.setLevel(logging.DEBUG)
    logger.propagate = False

    if logger.handlers:
        return logger                 # avoid duplicate handlers on reconfiguration

    formatter = logging.Formatter(
        "%(asctime)s %(levelname)s %(name)s %(message)s"
    )

    console = logging.StreamHandler()
    console.setLevel(logging.INFO)
    console.setFormatter(formatter)

    file_handler = RotatingFileHandler(
        "billing.log",
        maxBytes=5_000_000,
        backupCount=3,
        encoding="utf-8"
    )
    file_handler.setLevel(logging.DEBUG)
    file_handler.setFormatter(formatter)

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


def charge(card_reference, amount, logger):
    logger.info("Charge requested", extra={"amount": amount})
    try:
        if amount <= 0:
            raise ValueError("amount must be positive")
        # External payment operation would occur here.
        logger.info("Charge completed", extra={"amount": amount})
    except ValueError:
        logger.exception("Charge rejected")
        raise

The example is intentionally incomplete as a payment system. In a real application, card_reference would not be written to the log, the amount would have a defined currency, and the payment provider’s identifier would be handled according to security and compliance requirements.

9. Case Study: Diagnosing a Failed Batch Import

This is an illustrative case. A college administration system imports enrolment files each night. Staff report that some files appear to complete, but several student records are missing the following morning.

Background and Problem

The import process writes a single message, Import finished, even when individual rows fail. It catches exceptions and continues without recording the row number. Operators cannot distinguish a complete import from a partially successful one.

Analysis

The team defines an import correlation ID and records structured events for file receipt, row validation, database write, row rejection, and final outcome. Each event includes the file name, batch ID, row number where appropriate, and counts. Personal data is excluded.

The revised outcome distinguishes:

• total rows received;
• rows accepted;
• rows rejected;
• unexpected system errors; and
• final status: success, partial, or failed.

A row-level validation failure is logged at WARNING because the process can continue. A database connection failure is logged with a traceback at ERROR, and the batch is marked failed. The final summary is logged at INFO.

Approach and Solution

The application sends normal operational logs to standard output and retains rotated diagnostic logs for a defined period. A monitoring rule alerts when the partial-import count exceeds an agreed threshold. A dashboard displays accepted and rejected row counts rather than simply counting “finished” messages.

Outcome

Operators can identify the exact batch and row range affected, distinguish bad input from infrastructure failure, and rerun only the appropriate file after correction. The system’s logs now support an operational decision instead of merely documenting that a process reached its last line.

Learning Points

A successful process termination is not equivalent to successful business completion. Log the business outcome, not only the control-flow outcome. Stable fields, correlation IDs, explicit status values, and appropriate traceback use make evidence actionable.

10. Limitations, Security, and Professional Practice

Logging has costs. Formatting, serialization, disk writes, lock contention, and network transmission consume resources. High-volume DEBUG logging can materially affect latency. Use level checks or lazy formatting for expensive work, and use asynchronous collection when appropriate.

Security controls should include:

• data minimization and redaction;
• access control and audit trails for log readers;
• integrity protection where logs may be evidence;
• synchronized or consistently interpreted timestamps;
• defined retention and deletion periods; and
• protection against log injection, in which untrusted input inserts misleading lines or control characters.

Do not place raw user input into a message without considering newlines and escaping. Do not expose internal tracebacks in responses to end users. Return a safe error message and retain detailed evidence in restricted operational systems.

Artificial intelligence can assist with log clustering, anomaly detection, and summarization, but automated conclusions must be verified. Models may miss rare failures, infer causation incorrectly, or process confidential data inappropriately. Human ownership remains necessary for incident decisions, retention policy, and regulatory compliance.

Best-Practice Checklist

• Create one named logger per module with logging.getLogger(__name__).
• Configure handlers centrally and avoid accidental duplication.
• Use levels consistently and document operational meanings.
• Prefer stable structured fields over prose-only messages.
• Include correlation identifiers for distributed operations.
• Use logger.exception() only in a relevant exception-handling context.
• Rotate or externally manage logs and define retention.
• Never log secrets or unnecessary personal information.
• Use metrics for aggregate rates and traces for cross-service request paths.
• Test logging configuration, failure paths, redaction, and disk-full behaviour.

Chapter Summary

Python logging provides a standard pipeline from LogRecord creation through logger thresholds, handlers, formatters, and filters. Levels communicate severity, while propagation and central configuration determine how records are routed. Structured logging adds stable fields that machines can search and aggregate. Exceptions represent abnormal control flow; tracebacks preserve technical causality, but they must be logged deliberately and protected from disclosure. Rotation and retention prevent uncontrolled storage growth. Observability combines logs with metrics, traces, and other evidence. The professional value of logging lies not in producing many messages, but in producing trustworthy, secure, correlated evidence that supports diagnosis and operational decisions.

Key Terms

Log record: A structured object describing one logging event.

Logger: An object used by application code to create records.

Handler: A component that sends records to a destination.

Formatter: A component that renders a record as text or another representation.

Filter: A component that accepts, rejects, or enriches records.

Root logger: The top-level logger in Python’s logger hierarchy.

Propagation: Passing a child logger’s record to ancestor handlers.

Severity level: A classification such as DEBUG, INFO, or ERROR.

Structured logging: Recording event data in named, machine-readable fields.

Correlation ID: An identifier used to associate events belonging to one operation.

Exception: An object representing an abnormal execution condition.

Traceback: The call-path information associated with an exception.

Exception chaining: Preserving an original cause when raising a new exception.

Log rotation: Replacing or renaming a log when a size or time condition is reached.

Retention: The policy governing how long records are stored.

Diagnostics: The collection and interpretation of evidence about system behaviour.

Observability: The ability to infer internal system state from external outputs.

Metrics: Numerical measurements aggregated over time.

Traces: Records of a request’s path across components.

Log injection: Manipulation of log output through untrusted input.

Review Questions

Short Answer Questions

1. What is the difference between a logger and a handler?
2. Why can an exception exist without being logged?
3. What is the purpose of logger.exception()?
4. Explain why log rotation is operationally important.
5. Name two types of evidence that complement logs.

Long Answer Questions

1. Explain Python’s logging hierarchy, including effective levels, propagation, and handlers.
2. Compare plain-text logging with structured logging and discuss their operational trade-offs.
3. Describe how exception chaining and traceback logging improve diagnosis.
4. Design a logging policy for a batch-processing application, including levels, fields, retention, and privacy controls.
5. Explain why logs alone are insufficient for full observability.

Analytical / Application Questions

1. A service prints every error twice after a new module is added. Analyse the likely role of propagation and propose a configuration correction.
2. A production log contains a user’s password and a complete traceback in an HTTP response. Identify the risks and specify corrective actions.
3. An import job reports finished, but 4% of rows were rejected. Design structured events and an operational decision rule that would distinguish successful, partial, and failed imports.

Multiple Choice Questions with Answers

Question 1

Which component sends a Python log record to a destination such as a file or console?

A. Formatter

B. Handler

C. Filter

D. Exception

Correct Answer: B. Handler

Question 2

What normally happens to a DEBUG record when the effective logging level is INFO?

A. It is emitted as INFO

B. It is converted into a traceback

C. It is discarded

D. It is always written to every file

Correct Answer: C. It is discarded

Question 3

Which call is appropriate inside an except block when the current traceback should be included?

A. logger.exception("operation failed")

B. logger.debug("operation failed")

C. logger.info("operation failed", exc_info=False)

D. logger.disable("operation failed")

Correct Answer: A. logger.exception("operation failed")

Question 4

What is the main purpose of structured logging?

A. To remove timestamps from records

B. To make event fields consistently machine-readable

C. To ensure every event is an exception

D. To prevent all log rotation

Correct Answer: B. To make event fields consistently machine-readable

Question 5

Which handler is designed for size-based log rotation?

A. StreamHandler

B. NullHandler

C. RotatingFileHandler

D. MemoryHandler

Correct Answer: C. RotatingFileHandler

Question 6

Why can duplicate log messages occur in a logger hierarchy?

A. A formatter always formats twice

B. A child logger propagates to an ancestor that also has a handler

C. An exception automatically creates two messages

D. JSON serialization duplicates every field

Correct Answer: B. A child logger propagates to an ancestor that also has a handler

Question 7

Which item should generally not be written to application logs?

A. A request correlation ID

B. A bounded processing duration

C. A service name

D. A password or private key

Correct Answer: D. A password or private key

Question 8

What does exception chaining with raise NewError() from exc preserve?

A. The original exception as the cause

B. The logger’s configured handler

C. The file rotation count

D. The root logger’s level

Correct Answer: A. The original exception as the cause

Question 9

Which observability signal is most directly suited to following one request across several services?

A. Trace

B. Retention policy

C. Formatter

D. Severity threshold

Correct Answer: A. Trace

Question 10

A batch process catches a row-validation error and continues. Which level is usually most appropriate if the condition is unexpected but does not stop the batch?

A. DEBUG

B. INFO

C. WARNING

D. CRITICAL

Correct Answer: C. WARNING