OpenVelo Agent
127 lines
5.1 KiB
Markdown
127 lines
5.1 KiB
Markdown
---
|
|
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)
|