Add Logging to Automation Workflows

You've spent weeks writing Python scripts that delete stale S3 buckets, rotate database credentials, or sync Kubernetes manifests — and then one night, a job fails at 2 AM and you have zero idea why. Without structured, searchable logs, every automation failure becomes an archaeological dig through print statements and terminal scrollback. This lesson shows you how to add logging to automation workflows using Python's built-in logging module, so every run leaves a trail you can actually follow — from that first dry-run to a production incident review.

The problem this lesson solves

When automation runs unattended — in a cron job, a CI pipeline, or a Kubernetes pod — there's no human staring at the console. A simple print() statement disappears into a black hole the moment the process exits. You end up SSH'ing into boxes, grepping through systemd journals, or re-running the job with a debugger attached. That's slow, error-prone, and frankly, embarrassing when your manager asks, "What caused the outage at 03:14?"

Print-based debugging breaks down at scale for three reasons:

1. No severity levels — every message looks the same, so you can't filter for errors.
2. No timestamps — you can't reconstruct the sequence of events across multiple runs.
3. No stable output destination — stdout disappears in a containerized world, and stderr is only slightly better.

The logging module gives you a standard way to add logging to automation workflows: you attach handlers (files, streams, sockets) with formatters (timestamps, levels, module names) and let the logger route messages wherever you need them. The result is an audit trail that documents what ran, when it ran, and why it failed — exactly what DevOps teams need for debugging, compliance, and post-incident review.

Core concept / mental model

Think of the logging module as a postal service for your messages, with four moving parts:

• Logger — the sender. You create one per module (e.g., logger = logging.getLogger(__name__)), and it decides which messages are worth sending.
• Handler — the mailbox. It routes messages to a destination: StreamHandler for stdout, FileHandler for a log file, RotatingFileHandler for size-capped files.
• Formatter — the envelope. It adds context like timestamps, level names, and line numbers.
• Level — the postage. Messages below a severity threshold (DEBUG < INFO < WARNING < ERROR < CRITICAL) are never sent.

A message flows like this: your code calls logger.info("Backup started"), the logger checks the configured level, formats the message with your custom formatter, and the handler writes it to the destination.

Here's the mental model in plain terms: logging is not printing with extra steps — it's a configurable pipeline that lets you change where logs go and how much detail you capture without touching your application logic. Once you internalize the flow, you'll never reach for print() again for anything that needs to survive a reboot.

How it works step by step

Let's walk through adding logging to a simple automation script, from zero to a production-grade setup. You'll see the pattern once, then reuse it everywhere.

Step 1: Basic configuration

Start with the simplest possible setup — a single call to basicConfig() that configures the root logger. This is the "hello world" of logging.

import logging

logging.basicConfig(level=logging.INFO)
logging.info("Automation started")

When you run this, you'll see a line like INFO:root:Automation started on stderr. That's readable, but it's missing timestamps and context.

Step 2: Add a timestamp and custom formatter

It's better to capture when something happened. Add a format string and a date format.

import logging

logging.basicConfig(
    level=logging.INFO,
    format="%(asctime)s - %(levelname)s - %(name)s - %(message)s",
    datefmt="%Y-%m-%dT%H:%M:%S%z",  # ISO 8601 with UTC offset
)

logging.info("Automation started")

Output:

2025-03-14T09:30:00+0000 - INFO - root - Automation started

Pro tip: Use ISO 8601 timestamps (YYYY-MM-DDTHH:MM:SS) with a UTC offset in production logs. They're unambiguous, sortable, and every log aggregator (Datadog, Splunk, Loki) parses them natively.

Step 3: File output for persistence

On a server, you want logs to survive a process crash. Add a FileHandler via basicConfig by setting the filename argument.

import logging

logging.basicConfig(
    level=logging.INFO,
    format="%(asctime)s - %(levelname)s - %(message)s",
    handlers=[logging.FileHandler("automation.log")],
)

logging.info("Automation started")

The log now goes to automation.log, but you lose console output. In a container, you might want both — and that's where the next step comes in.

Step 4: Multiple handlers

Sometimes you need logs in two places: a file for audit, and stdout for your container logs. You'll need to create handlers explicitly and attach them to a logger.

import logging
import sys

# Create a logger for this module
logger = logging.getLogger("backup_job")
logger.setLevel(logging.DEBUG)

# Create a console handler that prints to stdout
console = logging.StreamHandler(sys.stdout)
console.setLevel(logging.INFO)

# Create a file handler that logs everything to a file
file_handler = logging.FileHandler("backup.log")
file_handler.setLevel(logging.DEBUG)

# Create a shared formatter
formatter = logging.Formatter("%(asctime)s - %(levelname)s - %(message)s")
console.setFormatter(formatter)
file_handler.setFormatter(formatter)

# Add handlers to the logger
logger.addHandler(console)
logger.addHandler(file_handler)

logger.info("Backup job started")

Now INFO-level messages appear on stdout, and DEBUG-level messages go to the file — perfect for troubleshooting later.

Step 5: Use module-level loggers

Getting a logger per module keeps your logs readable. Use __name__ so the logger name reflects the module path.

# file: backup_job.py
import logging
logger = logging.getLogger(__name__)


def run_backup(source, dest):
    logger.info(f"Backing up {source} to {dest}")
    # ... do work ...
    logger.info("Backup complete")

When you import this module elsewhere, the logger name is backup_job (or package.backup_job), making it easy to filter logs by module in your aggregator.

Step 6: Rotating log files

A log file that grows forever will eat your disk. Use RotatingFileHandler to split files when they reach a size limit.

import logging
from logging.handlers import RotatingFileHandler

logger = logging.getLogger("deployment")
logger.setLevel(logging.INFO)
handler = RotatingFileHandler("deploy.log", maxBytes=1_000_000, backupCount=5)
handler.setFormatter(logging.Formatter("%(asctime)s - %(levelname)s - %(message)s"))
logger.addHandler(handler)

logger.info("Deployment started")

This keeps deploy.log, deploy.log.1, up to deploy.log.5, capping total disk usage.

Hands-on walkthrough

Let's build a complete example: a script that checks disk usage on a fleet of servers and logs everything important. This mirrors a real DevOps automation task.

# disk_check.py
import logging
import subprocess
from pathlib import Path

logging.basicConfig(
    level=logging.INFO,
    format="%(asctime)s - %(levelname)s - %(name)s - %(message)s",
    handlers=[logging.FileHandler("disk_check.log")],
)
logger = logging.getLogger("disk_check")


def check_disk(hostname):
    """Return disk usage percentage for a remote host."""
    try:
        result = subprocess.run(
            ["ssh", hostname, "df", "--output=pcent", "/"],
            capture_output=True,
            text=True,
            timeout=10,
        )
        result.check_returncode()
        # Output is like: Use% 42%
        percent = int(result.stdout.strip().split()[-1].replace("%", ""))
        logger.info(f"{hostname}: disk usage {percent}%")
        return percent
    except subprocess.TimeoutExpired:
        logger.error(f"{hostname}: command timed out")
        return None
    except subprocess.CalledProcessError as e:
        logger.error(f"{hostname}: ssh failed with {e.returncode}")
        return None


servers = ["web01", "web02", "db01"]
threshold = 80
for host in servers:
    usage = check_disk(host)
    if usage is not None and usage > threshold:
        logger.warning(f"{host}: disk usage above threshold ({usage}%)")

When you run python disk_check.py, the file disk_check.log will contain lines like:

2025-03-14 09:45:12,345 - INFO - disk_check - web01: disk usage 72%
2025-03-14 09:45:12,567 - INFO - disk_check - web02: disk usage 85%
2025-03-14 09:45:12,789 - WARNING - disk_check - web02: disk usage above threshold (85%)
2025-03-14 09:45:13,101 - INFO - disk_check - db01: disk usage 34%

Notice how the warning stands out. In a real aggregator, you could trigger an alert on any WARNING line.

Now you try: Modify the script to also log to stdout, and set a debug variable that, when True, enables DEBUG-level logging. Observe the difference in output.

Compare options / when to choose what

How does Python's logging compare to other approaches? Use this table when deciding.

When to choose what:

• Stick with the standard library logging for most workflows — it's powerful, battle-tested, and requires zero pip installs.
• If you find yourself reconfiguring handlers everywhere, consider loguru for simplicity.
• If you're shipping logs to a central service, a JSON formatter is a wise investment; it makes parsing trivial.

Troubleshooting & edge cases

Even with good intentions, logging setups can backfire. Here are the pitfalls I've seen in production.

Problem: Logger configured but no output

Symptom: You set logger.info("Hello") but nothing appears. Fix: Check the logger's effective level. If the parent logger is set to WARNING, INFO messages are dropped. Use logger.setLevel(logging.DEBUG) and basicConfig(level=logging.DEBUG). Also ensure a handler is attached — basicConfig() only configures the root logger automatically.

Problem: Duplicate log lines

Symptom: Every message appears twice. Fix: This happens when you call basicConfig() more than once or when a logger has a handler and prints via a parent too. Disable propagation or remove existing handlers before adding new ones:

logger = logging.getLogger("my_logger")
logger.propagate = False  # prevent messages from bubbling to root

Problem: The % formatting breaks on % in messages

Symptom: logging.info("Disk usage: %s", usage) fails or logs %s literally. Fix: Use the logging module's lazy formatting: pass arguments separately. Never do logging.info(f"Disk usage: {usage}") if you care about performance or compatibility — but note that f-strings with % are fine, but %s in the format string is a problem. The rule: pass the format string and args separately.

logger.info("Disk usage: %s%%", usage)  # correct

Problem: Log file permissions in containers

When running in a Docker container, the log file may be owned by a non-writable user. Use a volume, or log to stderr and let the container runtime collect it. The twelve-factor app wisdom applies: write logs to stdout and let the orchestrator handle them.

Problem: Timezone confusion

You see timestamps in UTC but your dashboards show local time. Set your formatter to UTC, and convert at display time. This avoids ambiguity across team members in different timezones.

What you learned & what's next

You now understand how to add logging to automation workflows: the mental model of loggers, handlers, formatters, and levels; how to implement a file-based logger with rotation; and how to avoid common pitfalls like duplicate lines or missing output. You've also compared the standard library with alternatives like loguru and JSON logging.

Next in the Python for DevOps automation track, we'll explore how to structure a complete automation project — think multi-module scripts with proper error handling, configuration files, and testing. Your logging skills will be the backbone of that structure, because every serious automation project needs a reliable audit trail.

Go ahead and modify your disk check script to use a rotating file handler and a JSON formatter — you're ready.