Observable scripts: exit codes, logs, metrics & idempotency

Meaningful exit codes, structured logs, --dry-run, idempotency and audit trails.

A scheduled job runs while you sleep. Nobody is watching it. So the only things you have the next morning are whatever it left behind. A good night-shift cook leaves the kitchen clean and a note on the counter: what got prepped, what ran low, what broke. A bad one leaves nothing, and you cannot tell whether dinner is ready or the stove is still on. Observable automation is the good cook. This lesson is about the notes it leaves behind: an exit code that means something, structured logs your tooling can search, a --dry-run mode people trust, idempotency so a re-run is safe, and an audit trail for anything that changes state. Get these right and a black-box script becomes a thing you can operate, alert on, and defend.

The exit code is the one byte everyone reads

When a program finishes, it hands the operating system a single number from 0 to 255. That number is the whole verdict. Zero means it worked. Anything else means it did not, and the exact value says which way it broke. It is the one word a returning scout is allowed to shout across the camp: not the whole story, but enough for everyone to decide what to do next. The shell keeps that number in a variable called $? (the exit code of the last command). Your continuous integration system (CI, the service that builds and tests code automatically) branches on it. systemd (the program that starts and supervises services on most modern Linux machines) records it. So choose a small set of codes, give each one a distinct meaning, and write them down.

import sys
 
# Documented exit-code contract. CI, wrappers, and systemd all branch on these.
EXIT_OK      = 0   # everything converged
EXIT_ERROR   = 1   # nothing usable happened
EXIT_USAGE   = 2   # bad flags or bad input (matches most CLIs)
EXIT_PARTIAL = 3   # some targets done, some failed; safe to re-run the rest
 
def main(argv) -> int:
    try:
        args = parse_args(argv)
    except UsageError as e:
        log_event("error", msg="bad usage", detail=str(e))
        return EXIT_USAGE
    failures = run(args)                 # returns the list of targets that failed
    if failures and len(failures) < args.total:
        return EXIT_PARTIAL
    return EXIT_ERROR if failures else EXIT_OK
 
if __name__ == "__main__":
    sys.exit(main(sys.argv[1:]))         # the return value becomes the process exit code

That small table is the whole public interface of a command-line tool, and everything that wraps it reads the return value first. You do not get to pick every number, though. A code of 127 means the shell could not find the command; 126 means it found it but could not run it. Anything of the form 128 plus N means the process was killed by signal N, where a signal is a short message the kernel (the core of the operating system that talks to the hardware) sends to stop or interrupt a process. So 130 is Ctrl-C (SIGINT, signal 2), 143 is a polite stop from systemd (SIGTERM, signal 15), and 137 is a hard kill (SIGKILL, signal 9), most often from the out-of-memory killer (the kernel routine that starts killing processes when the machine runs out of RAM).

137 is 128 plus 9. The kernel sent SIGKILL, and the out-of-memory killer is the usual reason. A monitoring rule that sees 137 should send you to look at memory pressure, not at a bug in your rotation logic. This is why reusing reserved codes for your own failures is a trap: keep your codes in the low, unreserved range, and a reader can always tell your errors apart from the system's.

Structured logs your pipeline can actually search

A pile of free-text log lines is a shoebox of receipts. Everything is in there, but finding the three that matter means reading all of them. Structured logs are those same receipts typed into a spreadsheet, one row each, with columns you can filter. Emit one JSON object per event (JSON is JavaScript Object Notation, plain-text key and value data), carrying the fields that matter: what target, what action, what outcome. Send those log lines to standard error (stderr, the output stream meant for diagnostics) and keep standard output (stdout, the stream meant for results) for the tool's real data. Then a caller can pipe your output straight into another program without your log noise landing in it.

Under systemd, both streams land in journald (systemd's logging service, usually called the journal) with no setup. You write to stderr; the journal captures each line as one entry, stamped with metadata you never had to add. You read it back with journalctl, filtering by unit, by time window, or by priority. Priority here is the syslog severity level (syslog is the old, standard Unix logging scheme), a number that runs from 0 for emergency up to 7 for debug. The one-liner below reshapes a single entry with jq (a small command-line tool for querying and reformatting JSON) so you can see exactly what journald recorded.

The fields that begin with an underscore are the ones you can trust. journald writes them from outside your process, so a compromised script cannot forge them. _UID and _CMDLINE record which account ran which exact command line, with no cooperation from the program. That is a tamper-resistant answer to who ran what, sitting in the journal for free. One caveat on filtering: PRIORITY is journald's own severity, and a plain stderr line defaults to info (6) no matter what your JSON says. If you want journalctl -p warning to track your own level field, emit through systemd's native journal protocol (for example systemd-cat -p warning) so the severities line up.

Dry-run and idempotency

A light switch is idempotent. Flip it on and the room lights up; flip it on again and the room is still lit, no change and no harm. A doorbell is not: press it twice and it rings twice. You want your automation to behave like the switch. Idempotency means a second run leaves the system exactly as the first run left it, because every action checks the current state before it touches anything. A re-run after a half-finished failure is then safe, which is the entire point, because partial failures are normal and you must be able to run again without holding your breath.

--dry-run is the rehearsal. It computes the exact change, prints it, and exits without touching a thing. It is how people build the nerve to point your tool at production. Wire the two together so the same code path that decides whether to act also decides what dry-run reports. Then the preview can never lie about what the real run will do.

import sys, json
 
def log_event(level, **fields):
    # one JSON object per event, on stderr; journald stamps the timestamp
    print(json.dumps({"level": level, **fields}), file=sys.stderr)
 
def ensure_key(client, target, dry_run: bool) -> str:
    current = client.get_key(target)              # what is live right now
    if current and current.age_days < 30:
        log_event("info", action="rotate", target=target, result="unchanged")
        return "unchanged"                         # no drift: idempotent no-op
    if dry_run:
        log_event("info", action="rotate", target=target,
                  result="would-rotate", dry_run=True)
        return "would-rotate"
    client.rotate_key(target)                      # safe to re-run: it re-checks first
    log_event("info", action="rotate", target=target, result="rotated", count=3)
    return "rotated"

Three runs, three honest answers. The would-rotate line changed nothing. The rotated line did the work once. The third run found no drift and did nothing, and that quiet third answer is the proof that the tool is safe to schedule, safe to retry, and safe to run twice by accident.

Metrics that reveal a job that stopped running

A night watchman calls in every hour. Nobody really listens to the calls; they listen for a missing one. A log line is one of those calls, proof that a run happened. A metric is the thing that notices the call that never came. That absence is the failure log-based alerting misses, because a job that never starts writes no error line to search for. The most useful single number a recurring job can publish is the timestamp of its last success. Watch the age of that number and you catch the silent death that no log will report.

On a host, the short path is the node_exporter textfile collector. node_exporter (the agent that Prometheus scrapes for machine metrics, Prometheus being a database that pulls numbers off your fleet on a schedule) reads every file ending in .prom in one directory and serves whatever it finds. So your job writes a small text file: a gauge (a metric type that holds one value which can move up or down) for the last-success time, and a count or two from the run.

# HELP sec_rotate_last_success_seconds Unix time of the last successful run.
# TYPE sec_rotate_last_success_seconds gauge
sec_rotate_last_success_seconds 1752718447
# HELP sec_rotate_keys_rotated Keys rotated on the most recent run.
# TYPE sec_rotate_keys_rotated gauge
sec_rotate_keys_rotated 3

Now one alert covers the whole class of silent failure. The expression time() - sec_rotate_last_success_seconds > 90000 fires when the job has not succeeded in a day, whether it errored, hung, or never ran because someone disabled the timer. For short-lived jobs with no host to scrape, push the same numbers to the Prometheus Pushgateway (a small service that holds metrics from jobs too brief to be scraped) instead of writing a file.

An audit trail you cannot quietly rewrite

An audit trail is a ledger kept in pen, not pencil. Every state change gets one line: who did it, when, against what, and how it came out. The worth of it is that you can add pages but not tear them out. For a security tool, that ledger is the first thing an incident reviewer and a compliance auditor both ask to see. Write one JSON object per line to a file that only ever grows, a shape often called JSON Lines, so each append is cheap and each entry parses on its own.

chattr (the change-attribute command) with +a sets the append-only flag on ext4 or xfs, the common Linux filesystems. With it set, any write that seeks backward or truncates the file is refused with a permission error, even for root. An attacker who lands on the box can still add lines, but cannot quietly delete the record of what they did before they got there. Erasing history now needs chattr -a first, which requires a specific kernel capability (CAP_LINUX_IMMUTABLE) and is itself a visible step. It raises the bar; it does not seal the box. A determined root can always flip the flag back, so ship these lines off the host as they are written, to a collector the tool's own account cannot reach. The record an attacker cannot touch is the one that already left the building.

A silent success looks exactly like doing nothing. A tool that exits 0, prints nothing, and writes no metric tells the same story whether it rotated every key or swallowed an error and skipped them all. You cannot tell the two apart until the day it matters. So make success loud enough to see. Log the count of things changed, stamp the last-success metric on every clean run, and let every failure raise a non-zero exit and a warning line. The job you never hear from is not the healthy one; it is the one you stopped watching.

Try this

Work through “An audit trail you cannot quietly rewrite” yourself on a sandbox you can throw away, following the commands above in order. Then break one step deliberately and re-run, so you have seen the failure before it finds you.

Takeaway

The trap worth remembering here: write metric files atomically or the collector reads garbage. Check that on your own systems before you need to, because it is cheaper to find on a quiet afternoon than during an incident.

Related