Operations: logs, health and traces

Status: written November 7, 2026 (Phase 9, Observability; DECISIONS_NEEDED 2026-11-07 observability (a) to (c) and (e)). The log format, /healthz/ops and the trace hooks are covered by apps/api/tests/test_observability.py. Trace export was checked in a separate environment with the otel extra and an in-memory exporter: requests driven through softwarden.wsgi.application as gunicorn serves it, and a worker job with an exception. It has not been pointed at a real collector, gunicorn itself hasn’t served a traced request, and nothing is deployed. Caddy’s error-log filter was checked by hand against caddy 2.11 with a refused upstream.

Logs

The app and the worker write one JSON object per line on stdout (docker compose logs app, docker compose logs worker). Docker rotates the logs at 10 MB × 5 files (compose.yaml x-logging).

To follow one request through the app, the worker and the audit log, search for its X-Request-ID:

docker compose logs app worker | grep '"request_id": "<id>"'

What a line never holds. Logs never contain a query string. The renewals calendar feed carries its secret in one (?token=), and runserver’s request lines and some exception messages would print it. Every line is also scrubbed of the configured secrets: Django’s key, the database password, the credential and backup keys, the ops token and the installation’s Anthropic key. They are replaced with [redacted] in the message, the request fields and the traceback (apps/api/softwarden/logs.py). The list of secrets is read again at most every 60 seconds, so a key changed in a running process (it isn’t, today: every one is read at start) would be redacted within a minute. Django’s own loggers go through the same formatter, including django.server (runserver’s request lines, which carry the query string) and the console handler Django adds in development.

Levels. A request that succeeds is logged at INFO, a 4xx at WARNING and a 5xx at ERROR, the levels Django uses. Django’s own Not Found: <path> line is replaced by the request line, which carries the request’s fields. A successful probe (/healthz, /readyz, /readyz/web) is logged at DEBUG, so the container healthcheck doesn’t fill the log. A failing probe keeps its level. SOFTWARDEN_LOG_LEVEL sets the root level (default INFO).

Requests that never reach Django. With gunicorn’s access log off, a request that never reaches the app has no softwarden.request line. Instead:

• A worker killed by gunicorn’s 120 s timeout is a gunicorn.error line (WORKER TIMEOUT), and Caddy logs the 502 it then answers.
• A request gunicorn can’t parse is answered 400 by gunicorn and logged by it at DEBUG only (not shown at the default INFO).
• Anything Caddy can’t pass on (the app restarting, refused or timed-out connections) is a Caddy http.log.error line in docker compose logs proxy, with the status (502, 504) and the request’s method, host and URI.

Caddy’s error lines carry the full URI, query string included, so they were the one place the calendar feed’s secret could still be logged. The Caddyfile’s global log block filters request>uri and deletes the token parameter, which leaves the other parameters. If you replace the Caddyfile, or add an access log, keep that filter.

Local reading. SOFTWARDEN_LOG_FORMAT=text gives time level logger message [request_id=... org=... path=...] lines instead, scrubbed the same way. Any value other than json or text stops start-up.

/healthz/ops, the operator health view

GET /healthz/ops (next to /healthz, outside the documented /api/v1) returns installation-wide health in one JSON document:

It never contains an organization’s name or data, nor any secret. The job counts are totals and the schedule names are defined in code.

Status codes. The view answers 200 whenever the database answers, and status says how things stand. It answers 503 (database.state: unreachable) when the database doesn’t answer. Keep /readyz as the probe to alert on, and use /healthz/ops for detail and dashboards.

Who can open it. Only two callers get an answer. Everyone else, including Editors, Viewers and a wrong token, gets a 404, so the view doesn’t advertise itself.

• A request with Authorization: Bearer <ops token>. The comparison is constant-time over SHA-256 digests (so it doesn’t reveal the token’s length) and needs no database, so the token still works while the database is down.
• A signed-in Admin session, only while the installation has exactly one organization that isn’t on the cloud edition (DECISIONS_NEEDED observability (e)). The job figures cover every organization, so on a multi-organization installation one tenant’s Admin must not see them; there, only the token opens the view. The role is the session’s current membership as everywhere else, so an SSO session stays confined to its organization, and an account that must change its password on any membership is refused.

The ops token. The init service generates it into the secrets volume as ops_token. The file is 0600 and owned by the app user, and it is never replaced once written. Read it on the host with:

docker compose exec app cat /data/secrets/ops_token

Or set your own with SOFTWARDEN_OPS_TOKEN in .env. Then no file is generated, and the variable wins over an existing one. To rotate the generated token, run docker compose run --rm init sh -c 'rm /data/secrets/ops_token && python -m softwarden.init_secrets' and then docker compose restart app worker. The app reads the token at start. Alternatively, change SOFTWARDEN_OPS_TOKEN and restart. The token appears in no response, audit event or log line.

Example from a monitor:

curl -fsS -H "Authorization: Bearer $OPS_TOKEN" https://softwarden.example.org/healthz/ops

Behind Caddy. The route is not blocked at the proxy. The app’s own check guards it, so an outside monitor can use it over HTTPS and an Admin can open it in the browser. To keep it on the internal network only, add handle /healthz/ops { respond "Not found" 404 } above the default handle in a Caddyfile of your own. The view then answers only inside the compose network, at http://app:8000/healthz/ops with the bearer header.

Container limits

compose.yaml gives every service a memory limit (mem_limit) and a process limit (pids_limit), so a runaway process stops its own container (Docker restarts it) instead of taking the host’s memory and PostgreSQL with it. The app image’s services and the MCP server also run on a read-only root filesystem with a tmpfs /tmp; a tmpfs lives in memory and counts toward its container’s limit. docker stats shows each container’s use against its limit; an out-of-memory restart shows as OOMKilled: true in docker inspect.

The proxy and request bodies. Caddy reads each request’s whole body into memory before it opens the upstream request (request_buffers in docker/Caddyfile, up to SOFTWARDEN_MAX_REQUEST_MB, 26 MiB by default), so a slow upload ties up only the proxy, never a gunicorn thread (PRE_RELEASE_REVIEW F-10). Its memory is therefore about 64 MiB plus SOFTWARDEN_MAX_REQUEST_MB for each upload in flight at once: 512m leaves room for 16 of the largest at once. Caddy sets its Go memory limit from the container’s, so it collects garbage harder before it reaches it. Past the limit the proxy is restarted and the requests in flight fail; the app, the database and the host are not touched. If you raise SOFTWARDEN_MAX_REQUEST_MB, raise the proxy’s mem_limit to about 64 MiB plus 16 times the new value, and the app’s /tmp to at least 4 times it (and its mem_limit by the same amount).

Changing a limit. Put the new value in a compose.override.yaml next to compose.yaml (Compose reads it automatically), then docker compose up -d:

services:
  proxy:
    mem_limit: 1g
  app:
    mem_limit: 2g
    tmpfs: ["/tmp:size=512m"]

Sessions

Sessions live in the database (django_session). When a session key changes (sign-in, organization switch, password change, impersonation start or stop, sign-out), the old key stays for two minutes as a tombstone with no session values, so a request still carrying it doesn’t sign the browser out (apps/api/core/sessions.py, docs/API.md “Session key changes”). A request that loses such a race is logged at INFO by softwarden.sessions, not as an error. The worker’s sessions.clear schedule (daily at 03:50 UTC) deletes expired sessions and tombstones; it shows on the System page with the other schedules. Nothing else deletes them, so a stopped worker lets the table grow but changes nothing for users.

End-of-life data (endoflife.date)

End-of-life tracking (Phase 11, apps/api/eol/) reads public data from endoflife.date into an installation-wide cache: the product list (eol_eolproduct), the release cycles of the products some organization tracks (eol_eolrelease) and the cache’s own state (eol_eolsyncstate). The screens and the API read only the cache, so a slow or unreachable endoflife.date never slows a page.

The daily refresh. The eol.refresh schedule (04:45 UTC; endoflife.date regenerates its data around 00:10 UTC) queues an eol.refresh job in the worker’s long lane. The job fetches https://endoflife.date/api/v1/products, then https://endoflife.date/api/v1/products/<name> for each tracked product, one at a time. Each request goes through the outbound guard (core/outbound.py, the public-only rule: every address the host resolves to must be public, and the connection is pinned to it), with a 15 s socket timeout, a 45 s deadline per request and a body cap (4 MB for the list, 2 MB per product). It sends If-None-Match with the ETag it last got, so an unchanged document is a 304 with no body, and the User-Agent Softwarden/<version> (+https://github.com/Softwarden/softwarden) (the PROJECT_URL setting). A 429 or 5xx, or an unreachable host, is retried twice (after 2 s and 4 s, or after Retry-After up to 60 s); a 301 is followed on the same host only. A product that fails keeps its cached cycles and records why (EolProduct.error, shown as the reason an unknown status is unknown); the others go on. The job fails, and is retried 1 and 4 minutes later, only when the product list can’t be read and nothing is cached. When someone maps a product whose cycles aren’t cached yet, a job for just that product is queued, so its status appears within a worker tick; while no product list has ever been read, it queues a full refresh instead, which brings the list too. A product answer that can’t be stored (not a JSON object, a missing releases) is that product’s error and the run goes on; a malformed list keeps the cached one. A product whose address redirects to a new name keeps its cycles under the old one and records the new name (renamed_to, shown on the tracked version as product_renamed_to), so it can be re-mapped. After each run the derived cycles of the products touched are recomputed; an end-of-life date that moved moves its reminder at the next hourly reminders.generate run, and the built-in “End of life” notification rule announces it (90, 30 and 7 days before, then every 30 days from the end-of-life date while the version is still end of life; a cycle endoflife.date flags end of life with no date counts from the day the version was tracked). Acknowledging a version’s reminder on Needs attention stops its repeats; snoozing pauses them through the snooze date. After the upgrade to notify 0013 the rule’s first hourly run records, without sending, the repeat each version already past its end of life is inside, so nothing bursts out: each is next emailed at its own next 30-day mark, within 30 days. That run syncs the rule’s reminders first, so flag-only versions (which had no reminder before) are baselined even if the hourly reminders.generate hasn’t run since the upgrade; a notice that was owed but not yet sent at that moment is recorded as a baseline, not sent. An organization whose End of life rule already had escalation steps keeps escalate_when_acknowledged on, so acknowledging doesn’t stop its repeats there. The System page lists the schedule with the others; GET /api/v1/end-of-life shows the cache’s last_run_at, last_success_at and last_error.

Refresh now: docker compose exec worker python manage.py eol_refresh (the list and every tracked product), or --product postgresql (repeatable) for some products only. It prints the counts: updated, unchanged, failed, not_found, rederived.

Air-gapped installs. Set SOFTWARDEN_EOL_ENABLED=0: nothing is fetched or queued, and eol_refresh refuses. On a machine with internet access, save the whole data set (every product with its cycles, a few MB) and load it on the server, as often as you like:

curl -fsSL -o eol-full.json https://endoflife.date/api/v1/products/full
docker compose exec -T worker python manage.py eol_import - < eol-full.json

eol_import also takes /api/v1/products (the list only) or /api/v1/products/<name> (one product), and a file path instead of -. It replaces the cycles of the products in the file and recomputes the derived cycles; source becomes import. Until a list has been read (a refresh, or importing /products or /products/full), mapping accepts any well-formed product name, and its status stays unknown until data for it arrives; a file that isn’t an endoflife.date document is refused with a message and nothing is stored.

What leaves the installation: product names in the URL path and the User-Agent. No organization, record or user data is sent. The data is endoflife.date’s, under the MIT license.

OpenTelemetry traces (optional)

The default image does not include OpenTelemetry. Trace export is on only when both of these hold:

1. The image is built with the otel extra: docker compose build --build-arg WITH_OTEL=1. Outside Docker, run uv sync --extra otel. The extra contains opentelemetry-sdk, opentelemetry-exporter-otlp-proto-http, opentelemetry-instrumentation-django and opentelemetry-instrumentation-psycopg.
2. OTEL_EXPORTER_OTLP_ENDPOINT is set for app and worker, for example http://otel-collector:4318. compose.yaml passes this variable through.

If the variable is unset, nothing from opentelemetry is imported. If the variable is set but the extra is missing, the process logs one warning and runs untraced.

When on:

• Each gunicorn worker traces every request (Django instrumentation) and every query (psycopg instrumentation).
• The worker traces each job as a job <kind> span, and its queries under it. A query outside any job (the tick’s own polling) isn’t traced, so the worker doesn’t send a root trace every few seconds. OTEL_TRACES_SAMPLER still decides for everything else.
• Request and job spans carry softwarden.request_id, the same id as the log lines and the audit events.
• The service name is OTEL_SERVICE_NAME, else softwarden-web or softwarden-worker.

The exporter is OTLP over HTTP/protobuf, so gRPC is not supported (that would need grpcio in the image). Set the SDK’s other standard variables in .env; both containers read it. These include OTEL_EXPORTER_OTLP_HEADERS for a collector’s API key, OTEL_EXPORTER_OTLP_TRACES_ENDPOINT, OTEL_EXPORTER_OTLP_CERTIFICATE, OTEL_TRACES_SAMPLER and OTEL_TRACES_SAMPLER_ARG.

What leaves the process. Every span passes through a scrubbing exporter before it is sent. Its name, every string attribute, every event’s attributes (an exception’s exception.message and exception.stacktrace) and its status description get the same scrub as a log line: query strings cut and configured secrets replaced with [redacted]. url.query is emptied, and the request hooks cut the query from http.target, http.url and url.full as soon as the span starts. Database spans carry each statement with its %s placeholders, never the parameter values, and the SQL commenter is off. Nothing else from a request body or header is recorded.

Don’t capture headers. The instrumentation can record request and response headers through OTEL_INSTRUMENTATION_HTTP_CAPTURE_HEADERS_SERVER_REQUEST and ..._SERVER_RESPONSE. Leave them unset. If you need one, never list Authorization (API, SCIM and ops tokens), Cookie or Set-Cookie (the session) or X-CSRFToken, and set OTEL_INSTRUMENTATION_HTTP_CAPTURE_HEADERS_SANITIZE_FIELDS to authorization,cookie,set-cookie,x-csrftoken. The scrubbing exporter removes only the secrets it knows, and an API token or a session cookie isn’t among them. The assistant’s Anthropic client keeps its own tracing off, with no spans, no content and no traceparent header (discovery/assistant.py OPEN_TELEMETRY), whatever the ANTHROPIC_OPEN_TELEMETRY_* variables say.