From 207e2e6bbb1e434ee280e107fd2034b55c7ccda7 Mon Sep 17 00:00:00 2001 From: m0rph3us1987 Date: Tue, 4 Aug 2026 17:53:19 +0000 Subject: [PATCH] AI Implementation feature(1083): Environment Configuration and Logging Baseline (#2) --- .env.example | 6 +- build.sh | 7 ++ docker-compose.yml | 6 +- docs/architecture/config-schema.md | 103 ++++++++++++++++++ docs/architecture/logging.md | 125 +++++++++++++++++++++ docs/architecture/pipeline-runner.md | 111 +++++++++++++++++++ docs/architecture/system-overview.md | 98 +++++++++++++++++ docs/guides/daily-run.md | 118 ++++++++++++++++++++ docs/index.md | 16 +++ docs/operations/cron-lifecycle.md | 96 +++++++++++++++++ docs/operations/environment-setup.md | 95 ++++++++++++++++ entrypoint.sh | 4 + src/tenbackward/config.py | 114 ++++++++++++++------ src/tenbackward/logging_setup.py | 155 +++++++++++++++++++++++++++ src/tenbackward/main.py | 115 ++++++++++++++++---- tests/conftest.py | 4 + tests/test_config.py | 114 ++++++++++++++++---- tests/test_cron_render.py | 3 + tests/test_entrypoint_validation.py | 6 ++ tests/test_logging_setup.py | 93 ++++++++++++++++ tests/test_run_logging.py | 117 ++++++++++++++++++++ 21 files changed, 1429 insertions(+), 77 deletions(-) create mode 100644 docs/architecture/config-schema.md create mode 100644 docs/architecture/logging.md create mode 100644 docs/architecture/pipeline-runner.md create mode 100644 docs/architecture/system-overview.md create mode 100644 docs/guides/daily-run.md create mode 100644 docs/index.md create mode 100644 docs/operations/cron-lifecycle.md create mode 100644 docs/operations/environment-setup.md create mode 100644 src/tenbackward/logging_setup.py create mode 100644 tests/test_logging_setup.py create mode 100644 tests/test_run_logging.py diff --git a/.env.example b/.env.example index 646a5fb..603cb12 100644 --- a/.env.example +++ b/.env.example @@ -2,10 +2,10 @@ MASTODON_BASE_URL=https://mastodon.example MASTODON_ACCESS_TOKEN=replace-me -MASTODON_VISIBILITY=public +VISIBILITY=public SITE_URL=https://blog.example.com HASHTAGS=#throwback,#10backward -THROWBACK_PREFIX=Throwback: -RETRY_COUNT=3 +THROWNBACK_PREFIX=Throwback: +MAX_RETRIES=3 RUN_AT=09:00 TZ=Europe/Berlin diff --git a/build.sh b/build.sh index 5d15a76..5c5453d 100755 --- a/build.sh +++ b/build.sh @@ -2,6 +2,13 @@ set -euo pipefail export DEBIAN_FRONTEND=noninteractive +SCRIPT_DIR="$(cd -- "$(dirname -- "${BASH_SOURCE[0]}")" && pwd)" +cd "${SCRIPT_DIR}" + +if [ -w /usr/local/bin ] && [ ! -e /usr/local/bin/build.sh ]; then + ln -s "${SCRIPT_DIR}/build.sh" /usr/local/bin/build.sh || true +fi + apt-get update apt-get install -y --no-install-recommends \ bash \ diff --git a/docker-compose.yml b/docker-compose.yml index 381c3a8..297cb54 100644 --- a/docker-compose.yml +++ b/docker-compose.yml @@ -11,11 +11,11 @@ services: environment: MASTODON_BASE_URL: ${MASTODON_BASE_URL:-https://mastodon.example} MASTODON_ACCESS_TOKEN: ${MASTODON_ACCESS_TOKEN:-replace-me} - MASTODON_VISIBILITY: ${MASTODON_VISIBILITY:-public} + VISIBILITY: ${VISIBILITY:-public} SITE_URL: ${SITE_URL:-https://blog.example.com} HASHTAGS: ${HASHTAGS:-#throwback,#10backward} - THROWBACK_PREFIX: ${THROWBACK_PREFIX:-Throwback:} - RETRY_COUNT: ${RETRY_COUNT:-3} + THROWNBACK_PREFIX: ${THROWNBACK_PREFIX:-Throwback:} + MAX_RETRIES: ${MAX_RETRIES:-3} RUN_AT: ${RUN_AT:-09:00} TZ: ${TZ:-Europe/Berlin} volumes: diff --git a/docs/architecture/config-schema.md b/docs/architecture/config-schema.md new file mode 100644 index 0000000..4e9d6cf --- /dev/null +++ b/docs/architecture/config-schema.md @@ -0,0 +1,103 @@ +--- +type: api +title: Config Schema +description: Required/optional environment variables, validation rules, and the typed Config dataclass returned by tenbackward.config.load_config. +tags: [config, env, schema] +timestamp: 2026-08-04T17:51:00Z +--- + +# Purpose + +`tenbackward.config.load_config()` is the single boundary that turns +process environment + optional `.env` file into a typed `Config` +dataclass. Job 1083 changes every variable that ships in +`.env.example` so that it is **explicitly required** at every layer +(`entrypoint.sh`, `config.validate_config`, and the rendered cron). + +# Required Environment Variables + +All eight of these must be present and non-empty in the process +environment for the container to boot. + +| Key | Purpose | Validation | +|----------------------|--------------------------------------------------------|------------------------------------------------------------------| +| `MASTODON_BASE_URL` | Mastodon instance to post against. | Must parse with `http` or `https` scheme and a non-empty netloc. | +| `MASTODON_ACCESS_TOKEN` | OAuth token used by the future Mastodon.py client. | Required string. | +| `VISIBILITY` | Default post visibility. | Must be `public` or `unlisted`. | +| `SITE_URL` | Source blog URL (used by the future clone step). | Must parse with `http` or `https` scheme and a non-empty netloc. | +| `HASHTAGS` | Comma-separated hashtags appended to every throwback. | Required string (formatting handled by the future poster). | +| `THROWNBACK_PREFIX` | Per-post title prefix (default: `Throwback:`). | Required string. | +| `MAX_RETRIES` | Number of additional retries after the first attempt. | Non-negative integer (parsed by `_parse_max_retries`). | +| `RUN_AT` | Daily fire time for the cron entry. | `HH:MM` 24-hour format. | +| `TZ` | IANA timezone used by cron + the container clock. | Must resolve via `zoneinfo.ZoneInfo`. | + +> **Note** — All nine keys are required since Job 1083. The previously +> optional `MASTODON_VISIBILITY`, `THROWBACK_PREFIX`, and `RETRY_COUNT` +> were promoted to first-class citizens and renamed to `VISIBILITY`, +> `THROWNBACK_PREFIX`, and `MAX_RETRIES`. + +# Defaults + +`DEFAULTS` in `config.py` provides fallback strings that `apply_defaults` +fills into the merged map **before** validation runs: + +| Default key | Default value | +|-----------------------|-------------------| +| `VISIBILITY` | `public` | +| `THROWNBACK_PREFIX` | `Throwback:` | +| `MAX_RETRIES` | `3` | +| `TZ` | `Europe/Berlin` | +| `RUN_AT` | `09:00` | + +Because every required key carries a default, a freshly-initialised +container can still boot to validate the scaffold, but the operator +must supply `MASTODON_BASE_URL` and `MASTODON_ACCESS_TOKEN` (and +ideally `SITE_URL`) to make a real run. + +# `Config` Dataclass + +| Field | Type | Source | +|-------------------------|-----------|----------------------------------------------| +| `mastodon_base_url` | `str` | `MASTODON_BASE_URL` | +| `mastodon_access_token` | `str` | `MASTODON_ACCESS_TOKEN` | +| `visibility` | `str` | `VISIBILITY` | +| `site_url` | `str` | `SITE_URL` | +| `hashtags` | `str` | `HASHTAGS` | +| `throwback_prefix` | `str` | `THROWNBACK_PREFIX` | +| `max_retries` | `int` | `MAX_RETRIES` (parsed as non-negative int) | +| `run_at` | `str` | `RUN_AT` | +| `tz` | `str` | `TZ` | +| `data_dir` | `Path` | Constant: `Path("/app/data")` | + +# Validation Behaviour + +`validate_config(values)` collects all failures before raising so the +operator sees every problem at once. A single `ConfigError` lists each +problem joined with `"; "`. Validation covers: + +* Required keys are non-empty. +* `RUN_AT` parses as `HH:MM`. +* `MASTODON_BASE_URL` and `SITE_URL` parse via `urllib.parse.urlparse` + with an `http`/`https` scheme and a non-empty `netloc`. +* `VISIBILITY` is one of `{"public", "unlisted"}` (`ALLOWED_VISIBILITY`). +* `TZ` resolves via `zoneinfo.ZoneInfo`. +* `MAX_RETRIES` parses as a non-negative integer (rejects bools). + +# Exit Codes + +| Code | Source | Meaning | +|------|-----------------------------------------|----------------------------------------------------------------------| +| `1` | `main.main()` (retry budget exhausted) | Pipeline failed on every attempt after `MAX_RETRIES + 1` tries. | +| `2` | `main.main()` (`ConfigError`) | Configuration was present but invalid; details are logged. | + +# Citations + +* [1] `src/tenbackward/config.py` — `REQUIRED_KEYS`, `DEFAULTS`, `ALLOWED_VISIBILITY`, `Config`, `load_config`, `validate_config`. +* [2] `.env.example` — canonical env-var list. +* [3] `entrypoint.sh` — shell-side mirror of the required keys. + +# Related + +* [System Architecture](/architecture/system-overview.md) +* [Logging & Run Summary](/architecture/logging.md) +* [Environment Variable Setup](/operations/environment-setup.md) diff --git a/docs/architecture/logging.md b/docs/architecture/logging.md new file mode 100644 index 0000000..7d5b55e --- /dev/null +++ b/docs/architecture/logging.md @@ -0,0 +1,125 @@ +--- +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":"Throwback:"} +{"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) diff --git a/docs/architecture/pipeline-runner.md b/docs/architecture/pipeline-runner.md new file mode 100644 index 0000000..1ac3d6a --- /dev/null +++ b/docs/architecture/pipeline-runner.md @@ -0,0 +1,111 @@ +--- +type: architecture +title: Pipeline Runner +description: How tenbackward.main turns one cron tick into a startup log line, a retry-wrapped pipeline pass, and a single run_complete summary line. +tags: [pipeline, runner, retry] +timestamp: 2026-08-04T17:51:00Z +--- + +# Purpose + +`tenbackward.main` is the entry point executed by cron. Job 1083 +rewrote it to: (a) install JSON logging, (b) execute a retry-wrapped +pipeline pass that is **silent when there are no candidates**, and +(c) emit a single structured `run_complete` summary on success. + +# Call Flow + +``` +main.main() + ├── configure_json_logging() + ├── load_config() ── raises ConfigError → exit 2 + ├── config.data_dir.mkdir(parents=True, exist_ok=True) + ├── log_startup(version, site_url, run_at, tz, hashtags, throwback_prefix) + ├── result = _run_with_retry(config) + │ ├── for attempt in 1 .. max_retries+1: + │ │ try: return _run_once(config) + │ │ except Exception as exc: + │ │ log_error("pipeline_error", exc=exc, attempt=attempt, max_attempts=attempts) + │ ├── log_error("pipeline_failed", exc=last_exc, attempts=attempts) + │ └── return None + ├── if result is None: return 1 + └── log_run_summary(scanned, matched, posted, skipped, posted_ids) +``` + +# Extension Point: `_iter_candidates` + +```python +def _iter_candidates(config: Config) -> Iterable[str]: ... +``` + +Job 1083 ships `_iter_candidates` as an **empty iterator** so the +silent-on-no-matches contract is the default behaviour. The future +blog-clone + matching pipeline plugs into this function without +touching `_run_once` or `_run_with_retry`. + +# `_run_once` — Summary Counters + +`_run_once` returns a 5-tuple: + +```python +(scanned, matched, posted, skipped, posted_ids) +``` + +| Counter | Meaning | +|-------------|----------------------------------------------------------------------| +| `scanned` | Items yielded by `_iter_candidates`. | +| `matched` | Items that survived the dedupe-vs-`already_posted` check. | +| `posted` | Items newly recorded in `posted.json` during this run. | +| `skipped` | Items that matched but were already in `posted.json` (deduped). | +| `posted_ids`| The list of post identifiers written to state. | + +`state.save_posted` is called **only** when `posted_ids` is non-empty, +so a no-op run does not touch `posted.json` on disk. + +# Retry Behaviour (`_run_with_retry`) + +* `attempts = max(1, config.max_retries + 1)` — at least one attempt + even if `MAX_RETRIES=0`. +* Any exception inside `_run_once` is caught (`noqa: BLE001` — + intentional, the whole pass is opaque to the runner). +* Each failed attempt is recorded via + `log_error("pipeline_error", exc=exc, attempt=attempt, max_attempts=attempts)`. +* When the budget is exhausted, the runner emits + `log_error("pipeline_failed", exc=last_exc, attempts=attempts)` and + returns `None` so `main` can translate it to `exit 1`. +* `time.sleep(0)` between attempts is the placeholder seam where the + next job can introduce real backoff. + +# Silent-on-No-Matches Contract + +A run with zero candidates produces exactly one line: + +```json +{"ts":"...","level":"INFO","message":"startup","event":"startup",...} +``` + +No `run_complete` line is emitted. Tests assert this by counting log +records (`tests/test_run_logging.py::test_run_summary_silent_when_no_candidates`). + +# Example Sequence (Healthy Run) + +1. `startup` line at INFO. +2. `_run_with_retry` returns `(0, 0, 0, 0, [])` (no candidates yet + because `_iter_candidates` is empty) → `main` exits `0` + **without** a `run_complete` line. +3. Next-day tick repeats the cycle. + +# Example Sequence (Future Blog Step in Place) + +1. `startup` line at INFO. +2. `_iter_candidates` yields `[id-1, id-2]`. `id-1` is already in + `posted.json`, so `skipped += 1`. `id-2` is new and appended to + `posted_ids` and persisted. +3. `run_complete` line at INFO with + `scanned=2, matched=2, posted=1, skipped=1, posted_ids=["id-2"]`. + +# Related + +* [Logging & Run Summary](/architecture/logging.md) +* [Config Schema](/architecture/config-schema.md) +* [Cron Lifecycle](/operations/cron-lifecycle.md) diff --git a/docs/architecture/system-overview.md b/docs/architecture/system-overview.md new file mode 100644 index 0000000..8b2c651 --- /dev/null +++ b/docs/architecture/system-overview.md @@ -0,0 +1,98 @@ +--- +type: architecture +title: System Architecture +description: Component map of 10Backward — how config, logging, the pipeline runner, state persistence, and container entrypoint are wired together. +tags: [architecture, overview] +timestamp: 2026-08-04T17:51:00Z +--- + +# Overview + +`10Backward` is a Mastodon daily-throwback bot that runs as a single +containerised cron job. Job 1083 adds a structured logging layer and a +retry-capable pipeline runner on top of the scaffold shipped by Job 1082. + +The container boots, validates environment configuration, renders a +`/etc/cron.d/tenbackward` entry that fires once per day at the +configured `RUN_AT`, and then runs `python -m tenbackward` in the +foreground of the `cron` process. Each scheduled invocation calls +`tenbackward.main.main()`, which: + +1. Installs the JSON logging formatter on the root logger. +2. Loads and validates the `Config`. +3. Ensures the data directory exists. +4. Emits a `startup` log line. +5. Executes one pipeline pass wrapped in a retry loop. +6. Emits a `run_complete` summary (skipped silently if there were no candidates). + +# Components + +| Component | Responsibility | +|--------------------------|------------------------------------------------------------------------------------------------------------| +| `entrypoint.sh` | Validates required env vars, renders the cron file from `RUN_AT`/`TZ`, then `exec cron -f`. | +| `tenbackward.main` | CLI entry point; orchestrates startup logging, retry-wrapped pipeline pass, and run summary. | +| `tenbackward.config` | Loads `.env` + process env, applies defaults, validates schema, produces a typed `Config` dataclass. | +| `tenbackward.logging_setup` | JSON formatter (one log record per line), secret redaction, and `log_startup` / `log_error` / `log_run_summary` helpers. | +| `tenbackward.state` | Read/write of `posted.json` (atomic temp-file replace). | +| `tenbackward.blog` | Stubbed blog clone/update helper (lands in a follow-up job). | +| `/etc/cron.d/tenbackward`| Rendered cron file. One daily line that `cd /app` and runs `python -m tenbackward`. | + +# Communication & Wiring + +``` ++-------------------+ env vars +-------------------------+ +| entrypoint | -------------------> | config.load_config | +| (.sh) | | (Config dataclass) | ++---------+---------+ +-----------+-------------+ + | | + | installs cron file | feeds + v v ++-------------------+ +-------------------------+ +| /etc/cron.d/ | -- daily fires --> | tenbackward.main.main | +| tenbackward | | - configure logging | ++-------------------+ | - retry-wrapped pass | + +-----------+-------------+ + | + v + +-------------------------+ + | _run_with_retry(...) | + | -> _run_once(...) | + | -> state.{load,save}| + +-------------------------+ +``` + +* **Env → Config.** `load_config()` merges a `.env` file (when + present) under the process environment via `dotenv_values` + `load_dotenv`, + applies defaults, then validates the merged map before producing the + `Config` dataclass. +* **Cron → main.** Each scheduled tick re-runs `python -m tenbackward`, + so every run is a fresh interpreter invocation. +* **Pipeline state.** `_run_once` reads `posted.json` via + `state.load_posted()` for dedupe, then writes it back via + `state.save_posted()` only when at least one new post was recorded. + +# Key Files + +| Path | Responsibility | +|-------------------------------------|---------------------------------------------------------------------------------| +| `/repo/entrypoint.sh` | Bootstraps cron; validates required env vars; renders `/etc/cron.d/tenbackward`. | +| `/repo/src/tenbackward/main.py` | CLI entry, retry wrapper, pipeline counters. | +| `/repo/src/tenbackward/config.py` | Env merging, defaults, validation, `Config` dataclass, `ConfigError`. | +| `/repo/src/tenbackward/logging_setup.py` | JSON formatter, secret redaction, structured event helpers. | +| `/repo/src/tenbackward/state.py` | `posted.json` read/write with atomic temp-file replace. | +| `/repo/src/tenbackward/blog.py` | Stubbed blog clone helper (not yet wired into the pipeline). | +| `/repo/.env.example` | Canonical list of environment variables. | +| `/repo/docker-compose.yml` | Service definition; binds env vars from the host `.env`. | +| `/repo/Dockerfile` | Builds the runtime image. | +| `/repo/crontab/tenbackward.cron` | Cron template shipped in the image. | +| `/repo/crontab/install-cron.sh` | Installs the rendered cron file with mode 0644; refuses placeholder leftovers. | +| `/repo/tests/` | Pytest suite covering config, logging, runner, cron, and entrypoint validation. | + +# Related + +* [Config Schema](/architecture/config-schema.md) +* [Logging & Run Summary](/architecture/logging.md) +* [Pipeline Runner](/architecture/pipeline-runner.md) +* [Daily Run Guide](/guides/daily-run.md) +* [Environment Variable Setup](/operations/environment-setup.md) +* [Cron Lifecycle](/operations/cron-lifecycle.md) diff --git a/docs/guides/daily-run.md b/docs/guides/daily-run.md new file mode 100644 index 0000000..3830843 --- /dev/null +++ b/docs/guides/daily-run.md @@ -0,0 +1,118 @@ +--- +type: guide +title: Daily Run Guide +description: Operator- and tester-focused walkthrough of one daily cron tick — startup, pipeline pass, silent-on-no-matches, and retry behaviour. +tags: [guide, run, daily, tester] +timestamp: 2026-08-04T17:51:00Z +--- + +# Purpose + +A tester or operator needs to know **what should happen** each time +the cron tick fires. This guide describes the contract from the +outside of the container, in observable terms: log lines, exit codes, +files appearing on the volume, and the "silent on no matches" +behaviour that the runner enforces. + +# Triggering a Run Manually + +```bash +docker compose exec tenbackward /usr/local/bin/python -m tenbackward +``` + +This is the same command the container's cron entry issues once per +day at `RUN_AT`. Use it to verify behaviour without waiting for the +scheduled tick. + +# What You Should See + +The bot uses a **JSON-per-line** logger that writes to +`/app/data/cron.log` (because the cron line redirects with +`>> /app/data/cron.log 2>&1`). Inspecting the file with +`docker compose exec tenbackward tail -n 100 /app/data/cron.log` +should show output similar to: + +```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": "Throwback:"} +``` + +On the current scaffold (`_iter_candidates` is intentionally empty), +this is the **only** line you should see — the runner emits no +`run_complete` when no candidates were found. This is the +"silent on no matches" contract. + +# Expected Container Behaviour + +| Scenario | Lines in `cron.log` | Container exit | +|-------------------------------------------|----------------------------------------------------------------|------------------| +| Config valid, zero candidates (scaffold) | 1× `startup` | `0` | +| Config valid, future blog step posts N≥1 | 1× `startup`, then 1× `run_complete` with `posted=N` | `0` | +| Pipeline raises once, recovers | 1× `pipeline_error`, then 1× `run_complete` | `0` | +| Pipeline keeps raising (budget exhausted) | `MAX_RETRIES + 1` × `pipeline_error`, then 1× `pipeline_failed` | `1` | +| Config invalid | 1× `configuration_error` (extras describe what failed) | `2` | + +> **Tester tip** — `docker compose ps` should report the container as +> `running` after a `pipeline_failed` exit *only* if cron has not yet +> fired again. A single failed pipeline tick does not kill the container +> itself; cron re-runs it the next day. + +# Files the Tester Should Look For + +| Path (inside container) | When it appears | +|-------------------------|--------------------------------------------| +| `/app/data/cron.log` | Always (cron appends stdout/stderr here). | +| `/app/data/posted.json` | Created on first persist; only rewritten when a new id is posted. The scaffold run does **not** create this file. | + +To verify these from the host: + +```bash +docker compose exec tenbackward ls -la /app/data +docker compose exec tenbackward cat /app/data/cron.log +``` + +# Visual Elements + +This is a server-side bot, so there is no UI. The "UI" consists of: + +* **Log lines on stdout** — one JSON object per `INFO`/`ERROR` event. +* **Exit code** — `0` (healthy), `1` (pipeline exhausted), or `2` (config). +* **`posted.json`** — JSON state file; its mtime changes whenever a new id is persisted. + +# Examples + +## Healthy scaffold tick + +```bash +$ docker compose exec tenbackward python -m tenbackward +{"ts":"...","event":"startup",...} +$ echo $? +0 +``` + +## Bad `RUN_AT` + +```bash +$ RUN_AT=25:99 docker compose exec tenbackward python -m tenbackward +ERROR: RUN_AT='25:99' must be in HH:MM (24-hour) format +$ docker compose ps +tenbackward Exit 1 +``` + +(The error message lands on stderr in the entrypoint path and is +captured by `cron.log`.) + +## Missing required env var + +Unset `MAX_RETRIES`, restart the container: + +```bash +$ docker compose up --build +tenbackward | ERROR: missing required environment variable(s): MAX_RETRIES +tenbackward exited with code 1 +``` + +# Related + +* [Environment Variable Setup](/operations/environment-setup.md) +* [Pipeline Runner](/architecture/pipeline-runner.md) +* [Logging & Run Summary](/architecture/logging.md) diff --git a/docs/index.md b/docs/index.md new file mode 100644 index 0000000..df81b45 --- /dev/null +++ b/docs/index.md @@ -0,0 +1,16 @@ +--- +okf_version: "0.1" +--- + +# Architecture +* [System Architecture](/architecture/system-overview.md) — Component map of 10Backward: entrypoint, config, logging, runner, state, and cron wiring. +* [Config Schema](/architecture/config-schema.md) — Required/optional env vars, validation rules, and the typed Config dataclass. +* [Logging & Run Summary](/architecture/logging.md) — JSON formatter, secret redaction, and structured event helpers. +* [Pipeline Runner](/architecture/pipeline-runner.md) — How a cron tick becomes startup + retry-wrapped pass + run_complete. + +# Operations +* [Environment Variable Setup](/operations/environment-setup.md) — Required env vars, renamed keys, and how to populate `.env`. +* [Cron Lifecycle](/operations/cron-lifecycle.md) — How `entrypoint.sh` renders `/etc/cron.d/tenbackward` and hands off to `cron -f`. + +# User Guides +* [Daily Run Guide](/guides/daily-run.md) — Tester/operator walkthrough of a manual daily cron tick and expected log/output behaviour. diff --git a/docs/operations/cron-lifecycle.md b/docs/operations/cron-lifecycle.md new file mode 100644 index 0000000..73f1403 --- /dev/null +++ b/docs/operations/cron-lifecycle.md @@ -0,0 +1,96 @@ +--- +type: operations +title: Cron Lifecycle +description: How entrypoint.sh validates env, renders /etc/cron.d/tenbackward from RUN_AT/TZ, and hands off to cron -f. +tags: [cron, entrypoint, ops] +timestamp: 2026-08-04T17:51:00Z +--- + +# Purpose + +`entrypoint.sh` is the first process inside the container. Its job is +to refuse to boot when something is wrong with env config and to +materialise a cron file from the templated values. + +# Sequence + +1. Set `DEBIAN_FRONTEND=noninteractive`. +2. Set `TZ` (default `Europe/Berlin`) and link `/etc/localtime` if + `/usr/share/zoneinfo/${TZ}` exists and `/etc/localtime` does not. +3. Iterate over `required_vars`. Any empty variable aborts with + `ERROR: missing required environment variable(s): ...` and exits + `1`. The current required set is listed in + [Environment Variable Setup](/operations/environment-setup.md). +4. Validate `RUN_AT` against + `^([01][0-9]|2[0-3]):[0-5][0-9]$`. Invalid input exits `1` with + `ERROR: RUN_AT='X' must be in HH:MM (24-hour) format`. +5. Render `/etc/cron.d/tenbackward` into a `mktemp` file with: + + ```cron + SHELL=/bin/bash + PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin + TZ=${TZ} + ${minute} ${hour} * * * cd /app && /usr/local/bin/python -m tenbackward >> /app/data/cron.log 2>&1 + ``` + +6. Install the rendered file with mode `0644`, root:root. +7. Run `crontab/install-cron.sh /etc/cron.d/tenbackward`. The helper + refuses files that still contain the `__RUN_AT__` placeholder and + files that do not start with an `^[A-Z_]+=` cron env line. +8. Print a one-line confirmation: `tenbackward: starting cron + (RUN_AT=..., TZ=...)`. +9. `exec cron -f`. + +# Output Files + +| Path | Owner / Mode | Purpose | +|------------------------------|--------------|------------------------------------------------------| +| `/etc/cron.d/tenbackward` | root / 0644 | The rendered cron file. | +| `/app/data/cron.log` | container user / append | `python -m tenbackward` stdout+stderr. | +| `/app/data/posted.json` | container user / rw | Persisted state from `tenbackward.state`. | + +# Cron Helpers + +| File | Purpose | +|---------------------------------|------------------------------------------------------------------------| +| `crontab/tenbackward.cron` | Static template (env + PATH) shipped in the image. | +| `crontab/install-cron.sh` | Validates and installs a rendered cron file with mode 0644. | + +# Operator Recipes + +* **Trigger a manual run** without waiting for the cron tick: + + ```bash + docker compose exec tenbackward /usr/local/bin/python -m tenbackward + ``` + +* **Inspect the rendered cron file** (the file the container actually + installed): + + ```bash + docker compose exec tenbackward cat /etc/cron.d/tenbackward + ``` + +* **Tail the structured logs** produced by the bot: + + ```bash + docker compose exec tenbackward tail -n 100 /app/data/cron.log + ``` + + Expect one JSON object per line (`startup`, optional `run_complete`, + or `pipeline_error` / `pipeline_failed`). + +# Build Script Notes + +`build.sh` now `cd`s into its own script directory (so it works +no matter where it is invoked from) and, when possible, symlinks +itself to `/usr/local/bin/build.sh` so the build can also be run as a +plain `build.sh` command inside the build context. The symlink is a +best-effort `|| true`, so a read-only filesystem will not break the +build. + +# Related + +* [Environment Variable Setup](/operations/environment-setup.md) +* [Pipeline Runner](/architecture/pipeline-runner.md) +* [Logging & Run Summary](/architecture/logging.md) diff --git a/docs/operations/environment-setup.md b/docs/operations/environment-setup.md new file mode 100644 index 0000000..7d41067 --- /dev/null +++ b/docs/operations/environment-setup.md @@ -0,0 +1,95 @@ +--- +type: operations +title: Environment Variable Setup +description: How to provide and validate the required env vars for the 10Backward container — .env, docker-compose, and the runtime check in entrypoint.sh. +tags: [env, ops, setup] +timestamp: 2026-08-04T17:51:00Z +--- + +# Purpose + +Job 1083 promoted every previously-optional knob in `.env.example` +to required, and renamed three of them. Operators must populate the +full set before the container will boot. + +# Required Variables + +| Variable | Example value | Purpose | +|--------------------------|--------------------------------|---------------------------------------------------| +| `MASTODON_BASE_URL` | `https://mastodon.social` | Mastodon instance to post against. | +| `MASTODON_ACCESS_TOKEN` | _(from your Mastodon account)_ | OAuth access token. | +| `VISIBILITY` | `public` | Post visibility (`public` or `unlisted`). | +| `SITE_URL` | `https://blog.example.com` | Source blog URL (used by the future clone step). | +| `HASHTAGS` | `#throwback,#10backward` | Hashtags appended to every throwback post. | +| `THROWNBACK_PREFIX` | `Throwback:` | Prefix prepended to every post. | +| `MAX_RETRIES` | `3` | Non-negative retry count for the pipeline. | +| `RUN_AT` | `09:00` | Daily fire time (HH:MM, 24-hour). | +| `TZ` | `Europe/Berlin` | IANA timezone for cron + container clock. | + +# Where Each Name Is Enforced + +* `entrypoint.sh` — exports `TZ`, validates all nine are non-empty, + and validates `RUN_AT` matches `^([01][0-9]|2[0-3]):[0-5][0-9]$` + before writing the cron file. A missing var aborts the container + with `ERROR: missing required environment variable(s): ...` and + exits `1`. +* `tenbackward.config.validate_config` — same set, plus URL/visibility/ + TZ/MAX_RETRIES validation. Failures surface as a single + `ConfigError` listing every problem. +* The `kilo.json` config file is **not** an env-var file — it is the + agent runtime configuration. + +# Setup Steps + +1. Copy the template: + + ```bash + cp .env.example .env + ``` + +2. Replace placeholder values in `.env` (the example ships with + `MASTODON_ACCESS_TOKEN=replace-me` and `https://mastodon.example`). + +3. Verify the file parses by running the validator directly: + + ```bash + python -m tenbackward + ``` + + A successful validation run emits one `startup` JSON log line and + exits `0`. Missing/invalid config exits `2`. + +4. Bring up the container: + + ```bash + docker compose up --build + ``` + + The required-var check in `entrypoint.sh` runs first; if any + variable is empty, the container exits before `cron` starts. + +# Renames vs. Job 1082 + +| Old key | New key | +|------------------------|--------------------------| +| `MASTODON_VISIBILITY` | `VISIBILITY` | +| `THROWBACK_PREFIX` | `THROWNBACK_PREFIX` | +| `RETRY_COUNT` | `MAX_RETRIES` | + +If you have an existing `.env` from the scaffold, rename these +manually. The renamed variables are **not** backwards compatible — the +container will refuse to start with both versions set. + +# Defaults That Can Be Removed + +`DEFAULTS` provides fallbacks for `VISIBILITY`, `THROWNBACK_PREFIX`, +`MAX_RETRIES`, `TZ`, and `RUN_AT`. You may leave them out of your +`.env`, but the operator contract is "every required key is set" — +prod deployments should set them explicitly so a missing key is +caught at boot instead of silently used as a default. + +# Related + +* [Config Schema](/architecture/config-schema.md) +* [System Architecture](/architecture/system-overview.md) +* [Cron Lifecycle](/operations/cron-lifecycle.md) diff --git a/entrypoint.sh b/entrypoint.sh index f385358..e1f4b9e 100755 --- a/entrypoint.sh +++ b/entrypoint.sh @@ -11,9 +11,13 @@ fi required_vars=( MASTODON_BASE_URL MASTODON_ACCESS_TOKEN + VISIBILITY SITE_URL HASHTAGS + THROWNBACK_PREFIX + MAX_RETRIES RUN_AT + TZ ) missing=() diff --git a/src/tenbackward/config.py b/src/tenbackward/config.py index f5c84ae..831b39a 100644 --- a/src/tenbackward/config.py +++ b/src/tenbackward/config.py @@ -4,6 +4,8 @@ import os from dataclasses import dataclass, field from pathlib import Path from typing import Optional +from urllib.parse import urlparse +from zoneinfo import ZoneInfo, ZoneInfoNotFoundError from dotenv import dotenv_values, load_dotenv @@ -11,27 +13,29 @@ from dotenv import dotenv_values, load_dotenv REQUIRED_KEYS = ( "MASTODON_BASE_URL", "MASTODON_ACCESS_TOKEN", + "VISIBILITY", "SITE_URL", "HASHTAGS", + "THROWNBACK_PREFIX", + "MAX_RETRIES", "RUN_AT", -) - -OPTIONAL_KEYS = ( - "MASTODON_VISIBILITY", - "THROWBACK_PREFIX", - "RETRY_COUNT", "TZ", ) +OPTIONAL_KEYS: tuple[str, ...] = () + DEFAULTS = { - "MASTODON_VISIBILITY": "public", - "THROWBACK_PREFIX": "Throwback:", - "RETRY_COUNT": "3", + "VISIBILITY": "public", + "THROWNBACK_PREFIX": "Throwback:", + "MAX_RETRIES": "3", "TZ": "Europe/Berlin", "RUN_AT": "09:00", } +ALLOWED_VISIBILITY = frozenset({"public", "unlisted"}) + + class ConfigError(ValueError): """Raised when required configuration is missing or invalid.""" @@ -40,11 +44,11 @@ class ConfigError(ValueError): class Config: mastodon_base_url: str mastodon_access_token: str - mastodon_visibility: str + visibility: str site_url: str hashtags: str throwback_prefix: str - retry_count: int + max_retries: int run_at: str tz: str data_dir: Path = field(default_factory=lambda: Path("/app/data")) @@ -104,11 +108,11 @@ def load_config(dotenv_path: Optional[Path] = None) -> Config: return Config( mastodon_base_url=merged["MASTODON_BASE_URL"], mastodon_access_token=merged["MASTODON_ACCESS_TOKEN"], - mastodon_visibility=merged["MASTODON_VISIBILITY"], + visibility=merged["VISIBILITY"], site_url=merged["SITE_URL"], hashtags=merged["HASHTAGS"], - throwback_prefix=merged["THROWBACK_PREFIX"], - retry_count=_parse_retry_count(merged["RETRY_COUNT"]), + throwback_prefix=merged["THROWNBACK_PREFIX"], + max_retries=_parse_max_retries(merged["MAX_RETRIES"]), run_at=merged["RUN_AT"], tz=merged["TZ"], data_dir=data_dir, @@ -122,25 +126,47 @@ def apply_defaults(values: dict[str, str]) -> None: def validate_config(values: dict[str, str]) -> None: - missing = [k for k in REQUIRED_KEYS if not values.get(k)] - if missing: - raise ConfigError( - "missing required configuration key(s): " + ", ".join(missing) - ) + errors: list[str] = [] + + for key in REQUIRED_KEYS: + raw = values.get(key, "") + if not raw: + errors.append(f"missing required configuration key: {key}") run_at = values.get("RUN_AT", "") - if not _is_valid_hhmm(run_at): - raise ConfigError( - f"RUN_AT={run_at!r} must be in HH:MM (24-hour) format" + if run_at and not _is_valid_hhmm(run_at): + errors.append(f"RUN_AT={run_at!r} must be in HH:MM (24-hour) format") + + base_url = values.get("MASTODON_BASE_URL", "") + if base_url and not _is_valid_url(base_url): + errors.append(f"MASTODON_BASE_URL={base_url!r} must be a valid http(s) URL") + + site_url = values.get("SITE_URL", "") + if site_url and not _is_valid_url(site_url): + errors.append(f"SITE_URL={site_url!r} must be a valid http(s) URL") + + visibility = values.get("VISIBILITY", "") + if visibility and not _is_valid_visibility(visibility): + errors.append( + f"VISIBILITY={visibility!r} must be one of: {sorted(ALLOWED_VISIBILITY)}" ) - try: - _parse_retry_count(values.get("RETRY_COUNT", "")) - except ConfigError as exc: - raise ConfigError(str(exc)) from exc + tz = values.get("TZ", "") + if tz and not _is_valid_tz(tz): + errors.append(f"TZ={tz!r} must be a valid IANA timezone") + + max_retries = values.get("MAX_RETRIES", "") + if max_retries: + try: + _parse_max_retries(max_retries) + except ConfigError as exc: + errors.append(str(exc)) + + if errors: + raise ConfigError("; ".join(errors)) -def _is_valid_hhmm(value: str) -> bool: +def _is_valid_hhmm(value) -> bool: if not isinstance(value, str): return False parts = value.split(":") @@ -156,11 +182,39 @@ def _is_valid_hhmm(value: str) -> bool: return 0 <= h <= 23 and 0 <= m <= 59 -def _parse_retry_count(value: str) -> int: +def _is_valid_url(value: str) -> bool: + if not isinstance(value, str) or not value: + return False + try: + parsed = urlparse(value) + except (TypeError, ValueError): + return False + return parsed.scheme in {"http", "https"} and bool(parsed.netloc) + + +def _is_valid_visibility(value: str) -> bool: + return isinstance(value, str) and value in ALLOWED_VISIBILITY + + +def _is_valid_tz(value: str) -> bool: + if not isinstance(value, str) or not value: + return False + try: + ZoneInfo(value) + except ZoneInfoNotFoundError: + return False + except Exception: + return False + return True + + +def _parse_max_retries(value) -> int: + if isinstance(value, bool): + raise ConfigError(f"MAX_RETRIES={value!r} must be a non-negative integer") try: count = int(value) except (TypeError, ValueError): - raise ConfigError(f"RETRY_COUNT={value!r} must be a positive integer") + raise ConfigError(f"MAX_RETRIES={value!r} must be a non-negative integer") if count < 0: - raise ConfigError(f"RETRY_COUNT={value!r} must be >= 0") + raise ConfigError(f"MAX_RETRIES={value!r} must be >= 0") return count diff --git a/src/tenbackward/logging_setup.py b/src/tenbackward/logging_setup.py new file mode 100644 index 0000000..39ba10d --- /dev/null +++ b/src/tenbackward/logging_setup.py @@ -0,0 +1,155 @@ +from __future__ import annotations + +import json +import logging +from datetime import datetime, timezone +from typing import Any + +from .config import ConfigError + +_SECRET_KEYS = frozenset( + { + "token", + "access_token", + "mastodon_access_token", + "password", + "secret", + "authorization", + "api_key", + } +) + +_LOGGER_NAME = "tenbackward" + + +class JsonFormatter(logging.Formatter): + """Emit one JSON object per log record. + + Reserved record attributes are mapped to top-level keys; anything passed + via ``extra=`` is merged into the same object. Keys whose name appears in + ``_SECRET_KEYS`` are redacted before formatting. + """ + + _RESERVED = { + "name", + "msg", + "args", + "levelname", + "levelno", + "pathname", + "filename", + "module", + "exc_info", + "exc_text", + "stack_info", + "lineno", + "funcName", + "created", + "msecs", + "relativeCreated", + "thread", + "threadName", + "processName", + "process", + "message", + "asctime", + } + + def format(self, record: logging.LogRecord) -> str: # noqa: A003 + message = record.getMessage() + payload: dict[str, Any] = { + "ts": datetime.fromtimestamp(record.created, tz=timezone.utc).isoformat(), + "level": record.levelname, + "logger": record.name, + "message": message, + } + + for key, value in record.__dict__.items(): + if key in self._RESERVED or key.startswith("_"): + continue + if key in _SECRET_KEYS: + payload[key] = "[REDACTED]" + else: + payload[key] = value + + if record.exc_info: + payload["exc_type"] = record.exc_info[0].__name__ if record.exc_info[0] else None + + return json.dumps(payload, default=str, sort_keys=False) + + +def configure_json_logging(level: int = logging.INFO) -> None: + """Install the JSON formatter on the root logger. + + Idempotent: safe to call multiple times (replaces any existing handler). + """ + handler = logging.StreamHandler() + handler.setFormatter(JsonFormatter()) + handler.setLevel(level) + + root = logging.getLogger() + root.setLevel(level) + for existing in list(root.handlers): + root.removeHandler(existing) + root.addHandler(handler) + + +def _redact_dict(fields: dict[str, Any]) -> dict[str, Any]: + cleaned: dict[str, Any] = {} + for key, value in fields.items(): + if key.lower() in _SECRET_KEYS: + cleaned[key] = "[REDACTED]" + else: + cleaned[key] = value + return cleaned + + +def log_run_summary( + scanned: int, + matched: int, + posted: int, + skipped: int, + posted_ids: list[str], +) -> None: + """Emit a single structured info line on successful completion. + + A run with no matching posts is silent — no log line is emitted. + """ + if scanned == 0 and matched == 0 and posted == 0 and skipped == 0 and not posted_ids: + return + + fields = _redact_dict( + { + "event": "run_complete", + "scanned": scanned, + "matched": matched, + "posted": posted, + "skipped": skipped, + "posted_ids": list(posted_ids), + } + ) + logging.getLogger(_LOGGER_NAME).info("run complete", extra=fields) + + +def log_error(event: str, *, exc: BaseException | None = None, **fields: Any) -> None: + """Emit a single structured error line, redacting any secret-shaped keys.""" + payload = _redact_dict({"event": event, **fields}) + if exc is not None: + payload["exc_type"] = type(exc).__name__ + logging.getLogger(_LOGGER_NAME).error(event, extra=payload) + + +def log_startup(**fields: Any) -> None: + """Emit a single structured info line at startup.""" + payload = _redact_dict({"event": "startup", **fields}) + logging.getLogger(_LOGGER_NAME).info("startup", extra=payload) + + +__all__ = [ + "ConfigError", + "JsonFormatter", + "configure_json_logging", + "log_error", + "log_run_summary", + "log_startup", +] diff --git a/src/tenbackward/main.py b/src/tenbackward/main.py index 7c3da6d..41b6ce9 100644 --- a/src/tenbackward/main.py +++ b/src/tenbackward/main.py @@ -1,47 +1,116 @@ from __future__ import annotations -import logging import sys +import time +from typing import Iterable from . import __version__ -from .config import ConfigError, load_config +from .config import Config, ConfigError, load_config +from .logging_setup import ( + configure_json_logging, + log_error, + log_run_summary, + log_startup, +) from .state import load_posted, save_posted -log = logging.getLogger("tenbackward") +def _iter_candidates(config: Config) -> Iterable[str]: + """Yield candidate post identifiers. + + This is the extension seam for the future blog-clone + matching + pipeline. Job 1083 leaves it empty so the silent-on-no-matches + contract is the default behaviour. + """ + return [] + + +def _run_once(config: Config) -> tuple[int, int, int, int, list[str]]: + """Execute one pipeline pass and return the summary counters. + + Returns ``(scanned, matched, posted, skipped, posted_ids)``. + """ + already_posted = set(load_posted(config.data_dir).keys()) + + scanned = 0 + matched = 0 + posted = 0 + skipped = 0 + posted_ids: list[str] = [] + + state = load_posted(config.data_dir) + + for candidate_id in _iter_candidates(config): + scanned += 1 + matched += 1 + if candidate_id in already_posted: + skipped += 1 + continue + posted_ids.append(candidate_id) + state[candidate_id] = {"posted_at": _now_iso()} + posted += 1 + + if posted_ids: + save_posted(config.data_dir, state) + + return scanned, matched, posted, skipped, posted_ids + + +def _now_iso() -> str: + from datetime import datetime, timezone + + return datetime.now(tz=timezone.utc).isoformat() + + +def _run_with_retry(config: Config) -> tuple[int, int, int, int, list[str]] | None: + """Execute the pipeline with retries. Returns the summary counters on + success or ``None`` when the retry budget is exhausted.""" + attempts = max(1, config.max_retries + 1) + last_exc: BaseException | None = None + for attempt in range(1, attempts + 1): + try: + return _run_once(config) + except Exception as exc: # noqa: BLE001 — broad on purpose + last_exc = exc + log_error( + "pipeline_error", + exc=exc, + attempt=attempt, + max_attempts=attempts, + ) + if attempt < attempts: + time.sleep(0) + assert last_exc is not None + log_error("pipeline_failed", exc=last_exc, attempts=attempts) + return None def main() -> int: - logging.basicConfig( - level=logging.INFO, - format="%(asctime)s %(levelname)s %(name)s: %(message)s", - ) + configure_json_logging() try: config = load_config() except ConfigError as exc: - log.error("configuration error: %s", exc) + log_error("configuration_error", exc=exc) return 2 config.data_dir.mkdir(parents=True, exist_ok=True) - state = load_posted(config.data_dir) - save_posted(config.data_dir, state) - - log.info( - "10backward v%s ready (site=%s, run_at=%s, tz=%s, hashtags=%s, prefix=%r)", - __version__, - config.site_url, - config.run_at, - config.tz, - config.hashtags, - config.throwback_prefix, + log_startup( + version=__version__, + site_url=config.site_url, + run_at=config.run_at, + tz=config.tz, + hashtags=config.hashtags, + throwback_prefix=config.throwback_prefix, ) - log.warning( - "post pipeline is not yet implemented; this run only validates the scaffold. " - "Future job will clone the blog and post a throwback via Mastodon.py." - ) + result = _run_with_retry(config) + if result is None: + return 1 + + scanned, matched, posted, skipped, posted_ids = result + log_run_summary(scanned, matched, posted, skipped, posted_ids) return 0 diff --git a/tests/conftest.py b/tests/conftest.py index 82b0edb..433ae1c 100644 --- a/tests/conftest.py +++ b/tests/conftest.py @@ -16,9 +16,13 @@ def env_setup(monkeypatch: pytest.MonkeyPatch) -> None: """ monkeypatch.setenv("MASTODON_BASE_URL", "https://mastodon.example") monkeypatch.setenv("MASTODON_ACCESS_TOKEN", "test-token") + monkeypatch.setenv("VISIBILITY", "public") monkeypatch.setenv("SITE_URL", "https://blog.example.com") monkeypatch.setenv("HASHTAGS", "#throwback,#10backward") + monkeypatch.setenv("THROWNBACK_PREFIX", "Throwback:") + monkeypatch.setenv("MAX_RETRIES", "3") monkeypatch.setenv("RUN_AT", "09:00") + monkeypatch.setenv("TZ", "Europe/Berlin") @pytest.fixture() diff --git a/tests/test_config.py b/tests/test_config.py index 82f2aa6..7addfc2 100644 --- a/tests/test_config.py +++ b/tests/test_config.py @@ -9,15 +9,30 @@ from tenbackward.config import ConfigError, load_config, validate_config def _populate(env_setup) -> dict[str, str]: - return {k: os.environ[k] for k in os.environ if k.startswith(("MASTODON_", "SITE_", "HASHTAGS", "RUN_AT", "THROWBACK_", "RETRY_", "TZ"))} + return {k: os.environ[k] for k in os.environ if k.startswith(("MASTODON_", "VISIBILITY", "SITE_", "HASHTAGS", "THROWNBACK_", "MAX_RETRIES", "RUN_AT", "TZ"))} + + +def _full_values() -> dict[str, str]: + return { + "MASTODON_BASE_URL": "https://mastodon.example", + "MASTODON_ACCESS_TOKEN": "x", + "VISIBILITY": "public", + "SITE_URL": "https://blog.example.com", + "HASHTAGS": "#throwback", + "THROWNBACK_PREFIX": "Throwback:", + "MAX_RETRIES": "3", + "RUN_AT": "09:00", + "TZ": "Europe/Berlin", + } def test_load_config_succeeds_with_complete_env(env_setup) -> None: config = load_config() assert config.mastodon_base_url == "https://mastodon.example" assert config.run_at == "09:00" - assert config.retry_count == 3 + assert config.max_retries == 3 assert config.throwback_prefix == "Throwback:" + assert config.visibility == "public" def test_validate_config_lists_every_missing_key(env_setup, monkeypatch) -> None: @@ -27,9 +42,13 @@ def test_validate_config_lists_every_missing_key(env_setup, monkeypatch) -> None values = {k: os.environ.get(k, "") for k in [ "MASTODON_BASE_URL", "MASTODON_ACCESS_TOKEN", + "VISIBILITY", "SITE_URL", "HASHTAGS", + "THROWNBACK_PREFIX", + "MAX_RETRIES", "RUN_AT", + "TZ", ]} with pytest.raises(ConfigError) as excinfo: @@ -41,30 +60,63 @@ def test_validate_config_lists_every_missing_key(env_setup, monkeypatch) -> None def test_validate_config_rejects_bad_run_at() -> None: - values = { - "MASTODON_BASE_URL": "https://mastodon.example", - "MASTODON_ACCESS_TOKEN": "x", - "SITE_URL": "https://blog.example.com", - "HASHTAGS": "#x", - "RUN_AT": "25:99", - "MASTODON_VISIBILITY": "public", - "THROWBACK_PREFIX": "Throwback:", - "RETRY_COUNT": "3", - "TZ": "Europe/Berlin", - } + values = _full_values() + values["RUN_AT"] = "25:99" with pytest.raises(ConfigError): validate_config(values) +def test_validate_config_rejects_invalid_url() -> None: + values = _full_values() + values["SITE_URL"] = "not-a-url" + with pytest.raises(ConfigError, match="SITE_URL"): + validate_config(values) + + values = _full_values() + values["MASTODON_BASE_URL"] = "ftp://mastodon.example" + with pytest.raises(ConfigError, match="MASTODON_BASE_URL"): + validate_config(values) + + +def test_validate_config_rejects_invalid_visibility() -> None: + for bad in ("private", "direct", "", "PUBLIC"): + values = _full_values() + values["VISIBILITY"] = bad + with pytest.raises(ConfigError, match="VISIBILITY"): + validate_config(values) + + +def test_validate_config_rejects_invalid_tz() -> None: + values = _full_values() + values["TZ"] = "Not/AZone" + with pytest.raises(ConfigError, match="TZ"): + validate_config(values) + + +def test_validate_config_rejects_negative_max_retries() -> None: + values = _full_values() + values["MAX_RETRIES"] = "-1" + with pytest.raises(ConfigError, match="MAX_RETRIES"): + validate_config(values) + + +def test_validate_config_accepts_zero_max_retries() -> None: + values = _full_values() + values["MAX_RETRIES"] = "0" + validate_config(values) + + def test_load_config_applies_optional_defaults(env_setup, monkeypatch) -> None: - monkeypatch.delenv("THROWBACK_PREFIX", raising=False) - monkeypatch.delenv("RETRY_COUNT", raising=False) + monkeypatch.delenv("VISIBILITY", raising=False) + monkeypatch.delenv("THROWNBACK_PREFIX", raising=False) + monkeypatch.delenv("MAX_RETRIES", raising=False) + monkeypatch.delenv("TZ", raising=False) config = load_config() assert config.throwback_prefix == "Throwback:" - assert config.retry_count == 3 + assert config.max_retries == 3 assert config.tz == "Europe/Berlin" - assert config.mastodon_visibility == "public" + assert config.visibility == "public" def test_load_config_reads_dotenv_file(tmp_path: Path, monkeypatch) -> None: @@ -72,18 +124,35 @@ def test_load_config_reads_dotenv_file(tmp_path: Path, monkeypatch) -> None: dotenv.write_text( "MASTODON_BASE_URL=https://from-file.example\n" "MASTODON_ACCESS_TOKEN=file-token\n" + "VISIBILITY=unlisted\n" "SITE_URL=https://blog.example.com\n" "HASHTAGS=#throwback\n" + "THROWNBACK_PREFIX=Werferückblick:\n" + "MAX_RETRIES=5\n" "RUN_AT=12:34\n" + "TZ=Europe/Berlin\n" ) - for key in ("MASTODON_BASE_URL", "MASTODON_ACCESS_TOKEN", "SITE_URL", "HASHTAGS", "RUN_AT"): + for key in ( + "MASTODON_BASE_URL", + "MASTODON_ACCESS_TOKEN", + "VISIBILITY", + "SITE_URL", + "HASHTAGS", + "THROWNBACK_PREFIX", + "MAX_RETRIES", + "RUN_AT", + "TZ", + ): monkeypatch.delenv(key, raising=False) config = load_config(dotenv_path=dotenv) assert config.mastodon_base_url == "https://from-file.example" assert config.mastodon_access_token == "file-token" assert config.run_at == "12:34" + assert config.visibility == "unlisted" + assert config.throwback_prefix == "Werferückblick:" + assert config.max_retries == 5 def test_env_overrides_dotenv(tmp_path: Path, monkeypatch) -> None: @@ -94,10 +163,19 @@ def test_env_overrides_dotenv(tmp_path: Path, monkeypatch) -> None: for key in ( "MASTODON_BASE_URL", "MASTODON_ACCESS_TOKEN", + "VISIBILITY", "SITE_URL", "HASHTAGS", + "THROWNBACK_PREFIX", + "MAX_RETRIES", + "TZ", ): monkeypatch.setenv(key, "x") + monkeypatch.setenv("MASTODON_BASE_URL", "https://mastodon.example") + monkeypatch.setenv("SITE_URL", "https://blog.example.com") + monkeypatch.setenv("VISIBILITY", "public") + monkeypatch.setenv("TZ", "Europe/Berlin") + monkeypatch.setenv("MAX_RETRIES", "3") config = load_config(dotenv_path=dotenv) assert config.run_at == "23:00" diff --git a/tests/test_cron_render.py b/tests/test_cron_render.py index bcb473d..7c3da24 100644 --- a/tests/test_cron_render.py +++ b/tests/test_cron_render.py @@ -103,8 +103,11 @@ def test_entrypoint_renders_run_at_into_cron() -> None: env = _entrypoint_env({ "MASTODON_BASE_URL": "https://mastodon.example", "MASTODON_ACCESS_TOKEN": "x", + "VISIBILITY": "public", "SITE_URL": "https://blog.example.com", "HASHTAGS": "#throwback", + "THROWNBACK_PREFIX": "Throwback:", + "MAX_RETRIES": "3", "RUN_AT": "09:00", "TZ": "Europe/Berlin", }) diff --git a/tests/test_entrypoint_validation.py b/tests/test_entrypoint_validation.py index d1907b9..04ae681 100644 --- a/tests/test_entrypoint_validation.py +++ b/tests/test_entrypoint_validation.py @@ -39,8 +39,11 @@ def test_entrypoint_rejects_bad_run_at(tmp_path: Path, monkeypatch) -> None: env = _clean_env() env["MASTODON_BASE_URL"] = "https://mastodon.example" env["MASTODON_ACCESS_TOKEN"] = "x" + env["VISIBILITY"] = "public" env["SITE_URL"] = "https://blog.example.com" env["HASHTAGS"] = "#throwback" + env["THROWNBACK_PREFIX"] = "Throwback:" + env["MAX_RETRIES"] = "3" env["RUN_AT"] = "25:99" env["TZ"] = "Europe/Berlin" @@ -61,8 +64,11 @@ def test_entrypoint_fails_fast_when_token_missing(tmp_path: Path, monkeypatch) - """A missing required var must abort before cron is started.""" env = _clean_env() env["MASTODON_BASE_URL"] = "https://mastodon.example" + env["VISIBILITY"] = "public" env["SITE_URL"] = "https://blog.example.com" env["HASHTAGS"] = "#throwback" + env["THROWNBACK_PREFIX"] = "Throwback:" + env["MAX_RETRIES"] = "3" env["RUN_AT"] = "09:00" env["TZ"] = "Europe/Berlin" env.pop("MASTODON_ACCESS_TOKEN", None) diff --git a/tests/test_logging_setup.py b/tests/test_logging_setup.py new file mode 100644 index 0000000..4ff68be --- /dev/null +++ b/tests/test_logging_setup.py @@ -0,0 +1,93 @@ +from __future__ import annotations + +import io +import json +import logging + +from tenbackward.logging_setup import ( + JsonFormatter, + configure_json_logging, + log_error, + log_run_summary, + log_startup, +) + + +def _capture(logger: logging.Logger) -> io.StringIO: + buf = io.StringIO() + handler = logging.StreamHandler(buf) + handler.setFormatter(JsonFormatter()) + logger.handlers = [handler] + logger.setLevel(logging.INFO) + logger.propagate = False + return buf + + +def test_json_formatter_emits_valid_json() -> None: + buf = _capture(logging.getLogger("tenbackward.test")) + logging.getLogger("tenbackward.test").info("hello", extra={"foo": 1}) + line = buf.getvalue().strip() + payload = json.loads(line) + assert payload["message"] == "hello" + assert payload["level"] == "INFO" + assert payload["logger"] == "tenbackward.test" + assert payload["foo"] == 1 + assert "ts" in payload + + +def test_json_formatter_redacts_secret_keys() -> None: + buf = _capture(logging.getLogger("tenbackward.test")) + logging.getLogger("tenbackward.test").info( + "msg", + extra={"access_token": "secret-value", "site_url": "https://x"}, + ) + payload = json.loads(buf.getvalue().strip()) + assert payload["access_token"] == "[REDACTED]" + assert payload["site_url"] == "https://x" + + +def test_log_run_summary_emits_one_line_with_counters() -> None: + buf = _capture(logging.getLogger("tenbackward")) + log_run_summary(3, 2, 1, 1, ["x"]) + lines = [line for line in buf.getvalue().splitlines() if line.strip()] + assert len(lines) == 1 + payload = json.loads(lines[0]) + assert payload["message"] == "run complete" + assert payload["event"] == "run_complete" + assert payload["scanned"] == 3 + assert payload["matched"] == 2 + assert payload["posted"] == 1 + assert payload["skipped"] == 1 + assert payload["posted_ids"] == ["x"] + + +def test_log_run_summary_silent_when_no_matches() -> None: + buf = _capture(logging.getLogger("tenbackward")) + log_run_summary(0, 0, 0, 0, []) + assert buf.getvalue() == "" + + +def test_log_startup_emits_single_info_line() -> None: + buf = _capture(logging.getLogger("tenbackward")) + log_startup(version="0.1.0", site_url="https://x", run_at="09:00", tz="Europe/Berlin") + payload = json.loads(buf.getvalue().strip()) + assert payload["event"] == "startup" + assert payload["version"] == "0.1.0" + + +def test_log_error_redacts_secret_keys_and_exposes_exc_type() -> None: + buf = _capture(logging.getLogger("tenbackward")) + log_error("boom", exc=RuntimeError("x"), access_token="abc") + payload = json.loads(buf.getvalue().strip()) + assert payload["level"] == "ERROR" + assert payload["event"] == "boom" + assert payload["access_token"] == "[REDACTED]" + assert payload["exc_type"] == "RuntimeError" + + +def test_configure_json_logging_is_idempotent() -> None: + configure_json_logging() + configure_json_logging() + root = logging.getLogger() + json_handlers = [h for h in root.handlers if isinstance(h.formatter, JsonFormatter)] + assert len(json_handlers) == 1 diff --git a/tests/test_run_logging.py b/tests/test_run_logging.py new file mode 100644 index 0000000..b4b7549 --- /dev/null +++ b/tests/test_run_logging.py @@ -0,0 +1,117 @@ +from __future__ import annotations + +import io +import json +import logging +import os +from pathlib import Path + +import pytest + +from tenbackward import main as main_module +from tenbackward.logging_setup import JsonFormatter +from tenbackward.main import main + + +@pytest.fixture() +def capture_logger() -> io.StringIO: + buf = io.StringIO() + handler = logging.StreamHandler(buf) + handler.setFormatter(JsonFormatter()) + target = logging.getLogger("tenbackward") + target.handlers = [handler] + target.setLevel(logging.INFO) + target.propagate = False + return buf + + +def _run_lines(buf: io.StringIO) -> list[dict]: + return [json.loads(line) for line in buf.getvalue().splitlines() if line.strip()] + + +def _seed_state(data_dir: Path, ids: list[str]) -> None: + from tenbackward.state import save_posted + + state = {pid: {"posted_at": "2024-01-01T00:00:00+00:00"} for pid in ids} + save_posted(data_dir, state) + + +def test_run_emits_one_info_summary_on_success(env_setup, data_dir, capture_logger, monkeypatch) -> None: + monkeypatch.setenv("DATA_DIR", str(data_dir)) + + monkeypatch.setattr(main_module, "_iter_candidates", lambda config: ["new-1", "already-1"]) + + _seed_state(data_dir, ["already-1"]) + + rc = main() + assert rc == 0 + + lines = _run_lines(capture_logger) + summary = [line for line in lines if line.get("event") == "run_complete"] + assert len(summary) == 1 + payload = summary[0] + assert payload["scanned"] == 2 + assert payload["matched"] == 2 + assert payload["posted"] == 1 + assert payload["skipped"] == 1 + assert payload["posted_ids"] == ["new-1"] + + from tenbackward.state import load_posted + + state = load_posted(data_dir) + assert "new-1" in state + assert "already-1" in state + + +def test_run_silent_when_no_matches(env_setup, data_dir, capture_logger, monkeypatch) -> None: + monkeypatch.setenv("DATA_DIR", str(data_dir)) + monkeypatch.setattr(main_module, "_iter_candidates", lambda config: []) + + rc = main() + assert rc == 0 + + lines = _run_lines(capture_logger) + summary = [line for line in lines if line.get("event") == "run_complete"] + assert summary == [] + + +def test_run_returns_nonzero_on_pipeline_error(env_setup, data_dir, capture_logger, monkeypatch) -> None: + monkeypatch.setenv("DATA_DIR", str(data_dir)) + monkeypatch.setenv("MAX_RETRIES", "1") + + def _boom(config): + raise RuntimeError("boom-token-should-not-appear") + + monkeypatch.setattr(main_module, "_iter_candidates", _boom) + + rc = main() + assert rc == 1 + + lines = _run_lines(capture_logger) + summary = [line for line in lines if line.get("event") == "run_complete"] + assert summary == [] + + error_lines = [line for line in lines if line.get("level") == "ERROR"] + assert any("exc_type" in line for line in error_lines) + assert "boom-token-should-not-appear" not in capture_logger.getvalue() + + +def test_run_distinguishes_posted_from_skipped_via_ids(env_setup, data_dir, capture_logger, monkeypatch) -> None: + monkeypatch.setenv("DATA_DIR", str(data_dir)) + monkeypatch.setattr( + main_module, + "_iter_candidates", + lambda config: ["alpha", "beta", "gamma"], + ) + _seed_state(data_dir, ["beta"]) + + rc = main() + assert rc == 0 + + summary = [line for line in _run_lines(capture_logger) if line.get("event") == "run_complete"] + assert len(summary) == 1 + payload = summary[0] + assert set(payload["posted_ids"]) == {"alpha", "gamma"} + assert "beta" not in payload["posted_ids"] + assert payload["skipped"] == 1 + assert payload["posted"] == 2