feat: Phase 1 — api/sys persistence, /correlate, sentinel request_id, structured filters by ashish-jabble · Pull Request #63 · nerdapplabs/fasten

ashish-jabble · 2026-06-26T10:44:33Z

Phase 1 of #58 — the durable-history slice. Stacked on #59 (Phase 0); base is feat/phase0-completeness-flags, so this diff shows only Phase 1. Merge #59 first.

Turns correlation from a best-effort, last-few-seconds feature into a contract over durable history. Four features, Python + Go parity (FR5):

What

FR1 — opt-in durable persistence for api/sys. A per-stream SQLite StreamStore (one table per stream, full row as JSON payload + indexed columns). The in-memory ring stays the hot write path; the store is a write-through sink; reads come from the store when configured, else the ring. Default off → ring-only, fully backward compatible. Wiring reuses the Phase 0 completeness seam, so a persisted stream's flag flips ring → store with no handler change. SQLite-only in v1 (Postgres stream store is a later phase). Config: Python api_store=/syslog_store= or FASTEN_API_DSN/FASTEN_SYSLOG_DSN; Go Config.APIStore/SyslogStore.

FR2 — GET /logs/correlate?request_id=X. One call returns every stream for an operation: {request_id, audit, api, sys, counts, completeness}. Pure fan-out + assembly over the existing per-stream paths — no new query semantics. The payoff: with FR1 on, it recovers rows long past the ring window.

Sentinel request_id invariant. Every stream row now always carries a non-empty request_id, stamped at the transport push chokepoint with namespaced sentinels (boot-/sched-/bg-/lib-/orphan-) when no real context is active. The per-process boot- id is shared (one startup window); orphans are per-row. This is what makes /correlate a contract instead of "fan out, hope the relevant sys lines weren't orphans."

§3.4 — indexed structured filters. /sys gains event + since/until; /api gains status + since/until — the fields the store already indexes, so discovery by something an operator knows is a fast lookup. Honoured identically ring-vs-store.

Demonstrated live (curl, before/after)

	persistence OFF (before)	persistence ON (after)
`/correlate?request_id=<old op>` buried under 2500 rows	`api: 0` (`ring`) — churned	`api: 1` (`store`) — recovered
`/api?status=502`	`[]` (aged out of ring)	`["/v1/checkout"]`

Phase 0 → Phase 1 branch: /correlate 404 → 200; context-less /sys row request_id <<none>> → boot-….

Review

A multi-agent review ran on this branch; fixes are included in the last two commits: Python write-through made resilient (a sink failure can't break the hot logging path, matching Go); cross-language method/path filters aligned to exact-match (FR5 parity); null-timestamp window agreement (COALESCE); doc-accuracy corrections; added coverage (write-through failure, combined filters, limit, null-timestamp).

Deferred to a follow-up (non-blocking): Python level filter still case-folds; Go StreamQuery.Status → *int and the store eq-map's silent unknown-key drop; sentinel boot-window edge case (upstream id with a sentinel-like prefix); Go stderr rate-limiting under sustained store outage.

Tests

New: Python test_stream_persistence.py, test_correlate.py, test_sentinel_request_id.py, test_structured_filters.py, test_phase1_review.py; Go stream_store_test.go, correlate_test.go, sentinel_test.go, structured_filters_test.go.

Local verification: Python suite 287 passed / 18 skipped. Go is vet/gofmt/build-clean but could not be executed in my environment (the cgo core lib can't be linked on this arch) — CI is the first run of the Go suite for this branch.

Refs #58

Persist the api and sys streams to a per-stream SQLite store so they gain queryable history beyond the bounded ring. Opt-in and default-off — without a store, both streams stay ring-only (backward compatible). - StreamStore (Python store/stream.py, Go stream_store.go): table per stream, full row as JSON payload + indexed columns (request_id, timestamp, level, service_id, event, method, path, status). Returns rows newest-first, byte-identical to what was pushed, with the same filter semantics as that language's ring so store and ring reads agree. - Write-through transport: the ring stays the hot write path; the store is a write-through sink. Reads for a persisted stream come from the store (durable depth); unpersisted streams read the ring. - Wiring reuses the completeness seam: when a stream store is configured it joins persisted_streams / persistedStreams, so the reader flag flips ring -> store with no handler change. Python resolves via FASTEN_API_DSN / FASTEN_SYSLOG_DSN or init(api_store=, syslog_store=); Go via Config.APIStore / Config.SyslogStore (caller owns the *sql.DB). - Go QueryAPI/QuerySyslog now return an error, surfaced as HTTP 500 like the audit reader; SQLite-only in v1 (Postgres stream store is a later phase). Tests: store roundtrip/filter, depth-beyond-ring, completeness flip to store, ring-only fallback, write-through sync — Python (executed, green) and Go (vet/build clean; executed in CI). Refs #58

Add a single reader endpoint that returns every stream for one request_id, so a consumer holding an id gets the whole operation in one call instead of stitching three. Fans out to the existing per-stream query paths (audit store + sys/api rings-or-stores) and assembles them — no new query semantics. Response: { request_id, audit[], api[], sys[], counts{}, completeness{} }. completeness reports each stream's durability class (store vs ring) so the consumer knows whether a stream could be silently truncated; once api/sys persist (FR1) the historical-investigation case recovers rows past the ring window, which the tests pin. Python: GET /correlate, request_id required (422 if missing). Go: GET /correlate, request_id required (400 if missing), query errors surfaced as 500 like the audit reader. Tests cover assembly, request_id isolation, empty/unknown id, missing-param, and the persisted depth-beyond-ring case — Python executed green; Go vet/build clean, executed in CI. Refs #58

Guarantee that every sys/api stream row carries a non-empty request_id, so /logs/correlate is a contract rather than best-effort: today a context-less row (boot, init, background work, lost-context async) has no request_id and silently drops out of any correlated view. - Sentinel namespaces (boot/sched/bg/lib/orphan) with mint + classify helpers: Python context.mint_sentinel/request_id_kind/is_sentinel; Go MintSentinel/RequestIDKind/IsSentinel. The prefix tells an operator what kind of context produced the row instead of "anonymous noise". - Enforced at the transport push chokepoint so every path (shims, middleware, drainer) is covered: a missing request_id is filled with the shared per-process boot id during startup, then a unique orphan id once the first real request has been seen. Explicit ids are never touched. - boot id is minted once per process in Init and passed to the transport, so /correlate?request_id=boot-<svc>-<id> returns the whole startup window (boot-error diagnosis becomes a real workflow). Tests (Python executed green; Go vet/build clean, runs in CI): mint/classify, boot-then-orphan transition, explicit id untouched, boot rows correlatable, and a conformance check that no stream row across a mixed workload ever lacks a request_id. Refs #58

Expose the fields the StreamStore already indexes as first-class reader query params, so discovery by something an operator knows (an event name, a status code, a time window) is a fast indexed lookup instead of a scan or a free-text search: - /logs/sys gains ?event= and ?since=/?until= - /logs/api gains ?status= and ?since=/?until= Filters are honoured identically whether the stream is ring-only or persisted (store reads add WHERE clauses on the indexed columns; ring reads filter in memory with the same semantics), so behaviour doesn't change with persistence. Go: QuerySyslog/QueryAPI now take a StreamQuery filter struct (no more positional churn as filters grow); StreamStore.Query takes a since/until window. Tests assert each filter on the ring and prove store/ring agree — Python executed green; Go vet/build clean, runs in CI. Refs #58

Multi-agent review follow-ups: - Write-through resilience (parity + robustness): Python transport now wraps each stream-store insert and swallows failures to stderr, matching Go, so a persistence sink failure can never break the hot logging path (previously a raise could propagate through the HTTP shim's finally and corrupt the response). New test injects a failing store and asserts the ring copy survives and the push returns normally. - Null-timestamp window agreement: stores now COALESCE(timestamp,'') in the since/until predicates so a timestamp-less row (e.g. a sentinel boot/orphan row) is filtered identically to the ring, which treats a missing timestamp as "". New ring-vs-store agreement test. - Doc accuracy: drop the "byte-for-byte identical to what was pushed" claim from both StreamStore docs (JSON round-trip normalises numbers — int decodes to float64 in Go) and note the SQL LIKE wildcard caveat on the Python path filter. - Document why Python _boot_over needs no lock (GIL + monotonic flag) where Go uses bootMu. - Added coverage: combined filters compose (status + since), limit truncates to the newest N. Refs #58

…rity) Resolves the cross-language filter divergence from the Phase 1 review: the Python ring + store matched method case-insensitively and path by substring, while the Go SDK matched both exactly. /api?path=checkout returned a row in Python and nothing in Go for the same deployment. Python now matches method and path exactly in both the ring (store/ring.py) and the persisted store (store/stream.py), so the two SDKs are interchangeable on these filters. Tests updated to assert exact-match in both languages (case-folded / substring queries now correctly return nothing). Note: `level` is still lowercased on the Python filter side (tied to the lowercase-severity convention) — a smaller, separate divergence left as-is. Refs #58

ashish-jabble · 2026-06-26T10:47:28Z

① Historical correlation depth (FR1)

One operation (req-OLD) across audit/api/sys, then buried under 2500 later api rows (ring holds 2000), then correlated:

	`GET /logs/correlate?request_id=req-OLD`
BEFORE (ring-only)	`counts: {audit:1, api:0, sys:1}` · `completeness:{api:"ring", sys:"ring"}` — api row churned out, lost
AFTER (persistence on)	`counts: {audit:1, api:1, sys:1}` · `completeness:{api:"store", sys:"store"}` — `/v1/checkout` recovered

② The `/correlate` endpoint (FR2)

	`GET /logs/correlate?request_id=…`
BEFORE (Phase 0)	HTTP 404 — no endpoint; consumer stitches 3 calls
AFTER (Phase 1)	HTTP 200 — `{audit, api, sys, counts, completeness}` in one call

③ Sentinel `request_id` invariant

A sys row written before any request (boot/init):

	first context-less `/sys` row
BEFORE (Phase 0)	`request_id: <<none>>` — orphan, drops out of correlation
AFTER (Phase 1)	`request_id: "boot-demo-svc-…"` — correlatable, self-describing

④ Structured filters (§3.4)

2501 api rows persisted; filter by status:

	`GET /logs/api?status=502`
BEFORE	`status` param didn't exist — ignored
AFTER (persisted)	`["/v1/checkout"]` — exact row; `[]` if ring-only (502 row aged out)

In one line: before, "find everything for this operation" only worked for the last few seconds of api/sys traffic and dropped context-less rows entirely; after, it works against durable history in one
call, and every row carries a request_id.

Two notes on the axes (since this tripped earlier):

persistence on/off demonstrates rows ①+④ (FR1 depth) — same branch, toggle FASTEN_DEMO_PERSIST.
Phase 0 vs Phase 1 branch demonstrates ②+③ (new code) — the sentinel isn't persistence-gated.

praveen-garg · 2026-06-29T17:32:40Z

In docs, we should explain

Can I treat this
result as the whole record, or just a recent window?

praveen-garg · 2026-06-29T17:40:49Z

Synchronous per-row commit on the hot logging path (main concern)

PushAPI/PushSyslog (Go) and push_api/push_syslog (Python) now do a synchronous INSERT +
commit() per row inline on the caller's thread (stream_store.go:90, stream.py:106). The
audit path was deliberately made async (queue + drainer, P1-15) precisely to keep emit
off the disk; stream persistence is write-through synchronous. With WAL + default
synchronous=FULL, that's an fsync per logged line / per HTTP request once persistence is
enabled. For a hot api/sys stream this is a real throughput cliff. It's opt-in, so it's
not a regression for existing users — but anyone who flips it on pays per-row fsync.
Worth either batching/async-draining stream writes like audit, or at minimum setting
PRAGMA synchronous=NORMAL (the standard WAL tuning, currently left default) and
documenting the cost.

A swallowed persist failure makes completeness:"store" lie — now with data loss

This is the phase0 naming gap compounded. When a store is attached, reads are served only
from the store; the ring is never read (transport.go:179, stdout.py query_*). But a
persist failure is intentionally swallowed to stderr (correct for the hot path). So on a
failing sink (full disk): the row lives only in the ring, reads bypass the ring, and
completeness still reports "store". Net: silently missing rows plus a flag asserting
durability. The stderr line is the only signal.
test_persist_failure_does_not_break_hot_path proves the swallow is intentional, but
nothing reconciles "store said durable / row isn't there." Consider degrading the flag
(or surfacing a sink-health bit) when a write fails.

Python drainer self-reports vanish from /sys when persistence is on (parity gap)

write_drainer_syslog pushes to the ring but does not call _persist (stdout.py:102) — it's
the only push path that skips the store. With syslog_store attached, /sys reads come
from the store, so the audit drainer's own self-report events disappear from the reader
API (they were visible in ring-only mode). Go has no separate drainer-syslog path — its
self-reports go through PushSyslog and do persist (engine.go:304) — so this is also a
Go/Python divergence. Either persist drainer events too, or document that they're
stderr-only and intentionally non-durable.

/correlate can silently truncate with no signal

Each stream is capped at limit (default 100) independently, and counts reflects returned,
not available (http.go:handleCorrelate, router.py:186). Unlike /audit (which has
offset/total), correlate gives a heavily-correlated request_id no truncation signal — you
can't tell 100-of-100 from 100-of-5000. Given the whole point is "the complete operation
in one call," a per-stream truncated/total would close the honesty gap that completeness
is otherwise trying to keep.

Minor

Time-window filter is lexicographic string compare (inWindow / COALESCE(timestamp,'') >= ?). Fine if every row's timestamp is identically-formatted UTC, but mixed precision or offset (...Z vs ...+00:00, .5 vs .500) mis-sorts. Worth a note that the window assumes canonical timestamps.
RequestIDKind prefix collision: a real request_id starting with
boot-/bg-/lib-/orphan-/sched- is misclassified as a sentinel, which would keep the boot
window open longer than intended (fasten.go:RequestIDKind, context.py:request_id_kind).
Low probability, low blast radius.
level filter parity: Python lowercases the query param (stream.py:145, ring.py:41); Go
matches exactly (no normalization). Pre-existing ring behavior, but the FR5 "exact-match
parity" commit didn't cover level.
Ring is dead weight when persistence is on — still written on every push but never
read. Intentional-looking (uniform write path), just noting the per-row allocation.
Sentinel enum is partly aspirational: the auto-stamp path only ever mints boot/orphan;
sched/bg/lib exist only for explicit caller use. Fine, but the enum implies more
automation than exists.

Addresses the Phase 1 review feedback: - completeness no longer lies on a failing sink: a swallowed stream-persist failure is recorded on the StreamStore (NoteWriteFailure / note_write_failure at the transport swallow point) and the reader degrades that stream's flag to "store-degraded" — reads bypass the ring once a store is attached, so a lost row is silently missing and plain "store" would assert durability the data no longer has. Sticky by design: the hole in history doesn't heal. - /correlate reports per-stream "totals" (matching rows in the backing source) alongside "counts" (returned), so consumers can tell 100-of-100 from 100-of-5000: filtered COUNT on the stream stores and the audit store (CountFiltered on SQLite/Postgres, count(**filters) in Python), ring match-count otherwise. - Python drainer self-reports now persist like every other syslog push (write_drainer_syslog was the only path skipping the store, making drainer events vanish from the reader API when persistence is on — Go/Python parity; the store insert can't reintroduce the stdout deadlock). - stream stores set PRAGMA synchronous=NORMAL (per-connection in Python; in migrate + DSN guidance in Go) and document the per-row write-through cost. - level filters are exact-match in Python (like method/path, matching Go), and the Go slog handler writes lowercase levels — the canonical casing every other writer uses — so slog rows are findable cross-language. - doc notes: lexicographic time-window assumption (canonical UTC timestamps), sentinel prefix-classification caveat, only boot/orphan are auto-minted. - READMEs answer "is this the whole record or a recent window?" — the store / ring / store-degraded contract and counts-vs-totals truncation detection.

…reams default Conflict resolution keeps both sides' semantics: Init seeds persistedStreams from a per-engine copy of defaultPersistedStreams then extends it with api/sys per config; streamSource keeps the nil-map fallback to the shared default AND the store-degraded classification; the router _source docstring merges the durability-class framing with the degraded contract, now pointing at /correlate totals-vs-counts as the per-response truncation signal.

A local-build symlink slipped into the merge commit: the .gitignore pattern 'fasten-core/target/' only matches directories, so a symlink by the same name was not ignored. CI then failed with 'failed to create directory fasten-core/target: Not a directory'. Remove it and drop the trailing slash so the pattern covers both.

ashish-jabble added 6 commits June 25, 2026 19:37

ashish-jabble requested a review from praveen-garg June 26, 2026 10:47

ashish-jabble added 3 commits July 2, 2026 13:56

praveen-garg approved these changes Jul 7, 2026

View reviewed changes

ashish-jabble merged commit d5cd0fa into feat/phase0-completeness-flags Jul 7, 2026
2 checks passed

ashish-jabble deleted the feat/phase1-persistence branch July 7, 2026 14:50

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Uh oh!

feat: Phase 1 — api/sys persistence, /correlate, sentinel request_id, structured filters#63

feat: Phase 1 — api/sys persistence, /correlate, sentinel request_id, structured filters#63
ashish-jabble merged 9 commits into
feat/phase0-completeness-flagsfrom
feat/phase1-persistence

ashish-jabble commented Jun 26, 2026

Uh oh!

ashish-jabble commented Jun 26, 2026

Uh oh!

praveen-garg commented Jun 29, 2026

Uh oh!

praveen-garg commented Jun 29, 2026

Uh oh!

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

2 participants

Uh oh!

Conversation

ashish-jabble commented Jun 26, 2026

What

Demonstrated live (curl, before/after)

Review

Tests

Uh oh!

ashish-jabble commented Jun 26, 2026

① Historical correlation depth (FR1)

② The /correlate endpoint (FR2)

③ Sentinel request_id invariant

④ Structured filters (§3.4)

Uh oh!

praveen-garg commented Jun 29, 2026

Uh oh!

praveen-garg commented Jun 29, 2026

Uh oh!

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

2 participants

② The `/correlate` endpoint (FR2)

③ Sentinel `request_id` invariant