---
type: architecture
title: Logging & Run Summary
description: Structured JSON logging in 10Backward — JsonFormatter, secret redaction, and the startup / error / run_complete event helpers.
tags: [logging, observability, json]
timestamp: 2026-08-04T17:51:00Z
---

# Purpose

`tenbackward.logging_setup` replaces the scaffold-era `basicConfig`
text logger with a **single-line JSON formatter** that downstream
log shippers can index. It also owns the three helpers the runner
uses to record structured events: `log_startup`, `log_error`,
`log_run_summary`.

# JsonFormatter

`JsonFormatter.format(record)` returns one JSON object per log record:

| Key        | Source                                                              |
|------------|---------------------------------------------------------------------|
| `ts`       | UTC `datetime.fromtimestamp(record.created).isoformat()`.           |
| `level`    | `record.levelname` (e.g. `INFO`, `ERROR`).                          |
| `logger`   | `record.name` (always `tenbackward`).                               |
| `message`  | `record.getMessage()`.                                              |
| _extras_   | Any keyword passed via `logging.info(..., extra={...})` that is not a reserved `LogRecord` attribute and whose key is **not** in `_SECRET_KEYS`. |
| `exc_type` | When `record.exc_info` is set, the exception class name.            |

Reserved `LogRecord` attributes and any key starting with `_` are
dropped before serialization, so the payload contains only the values
that callers intentionally attached.

## Secret Redaction

`_SECRET_KEYS` is the canonical denylist applied in two places:

1. **At format time** for keys passed via `extra={...}`.
2. **At helper time** by `_redact_dict(...)` so values reaching
   `log_startup` / `log_error` never expose known-sensitive fields
   even before they hit the formatter.

Deny-list contents (case-insensitive):

```
token, access_token, mastodon_access_token, password, secret,
authorization, api_key
```

Any matching key is replaced with the string `[REDACTED]`.

# Helper Functions

| Helper                                | When it fires                                                         | Logger / Level | `event` field      |
|---------------------------------------|-----------------------------------------------------------------------|----------------|--------------------|
| `configure_json_logging(level=INFO)`  | First line of `main.main()`. Idempotent — clears existing handlers.   | n/a            | n/a                |
| `log_startup(**fields)`               | After config load + `data_dir.mkdir`, before the pipeline pass.       | `INFO`         | `startup`          |
| `log_error(event, *, exc=None, **fields)` | When a pipeline attempt raises, or when the retry budget is exhausted. | `ERROR`     | the supplied event name; `exc_type` added when `exc` is provided. |
| `log_run_summary(scanned, matched, posted, skipped, posted_ids)` | Once per successful pass. **Silently skipped** when all counters are zero and no ids were posted. | `INFO`         | `run_complete`     |

## Startup payload

`log_startup` is invoked with:

```
version, site_url, run_at, tz, hashtags, throwback_prefix
```

Each is added to the `startup` event payload under its own key.

## Run-summary payload

`log_run_summary` is the canonical "what did the bot do today?" record:

```json
{
  "ts": "2026-08-04T09:00:00+00:00",
  "level": "INFO",
  "logger": "tenbackward",
  "message": "run complete",
  "event": "run_complete",
  "scanned": 0,
  "matched": 0,
  "posted": 0,
  "skipped": 0,
  "posted_ids": []
}
```

A pass with no candidates emits **no line at all**, matching the
"silent on no matches" contract.

# Examples

## Successful run with one new post

```json
{"ts":"2026-08-04T09:00:00+00:00","level":"INFO","logger":"tenbackward","message":"startup","event":"startup","version":"0.1.0","site_url":"https://blog.example.com","run_at":"09:00","tz":"Europe/Berlin","hashtags":"#throwback,#10backward","throwback_prefix":"Heute vor 10 Jahren:"}
{"ts":"2026-08-04T09:00:01+00:00","level":"INFO","logger":"tenbackward","message":"run complete","event":"run_complete","scanned":1,"matched":1,"posted":1,"skipped":0,"posted_ids":["2025-08-04-post-slug"]}
```

## Retry budget exhausted

```json
{"ts":"...","level":"ERROR","logger":"tenbackward","message":"pipeline_error","event":"pipeline_error","attempt":1,"max_attempts":4,"exc_type":"ConnectionError"}
{"ts":"...","level":"ERROR","logger":"tenbackward","message":"pipeline_error","event":"pipeline_error","attempt":2,"max_attempts":4,"exc_type":"ConnectionError"}
{"ts":"...","level":"ERROR","logger":"tenbackward","message":"pipeline_failed","event":"pipeline_failed","attempts":4,"exc_type":"ConnectionError"}
```

The container then exits with status `1`.

## Token accidentally logged

Even if a future call wrote `extra={"access_token": "..."}`, the
formatter replaces it:

```json
{ "...": "...", "access_token": "[REDACTED]" }
```

# Related

* [System Architecture](/architecture/system-overview.md)
* [Pipeline Runner](/architecture/pipeline-runner.md)
* [Config Schema](/architecture/config-schema.md)
* [Mastodon Publishing](/architecture/mastodon-publishing.md)