Skip to content

Decouple the telemetry emitter's event path from spool writes - #1174

Draft
MaxGhenis wants to merge 18 commits into
mainfrom
fix/telemetry-event-queue
Draft

MaxGhenis wants to merge 18 commits into
mainfrom
fix/telemetry-event-queue

Conversation

@MaxGhenis

Copy link
Copy Markdown
Contributor

Stacked on #1168. This PR targets main so CI runs, and until #1168 merges its diff includes #1168's commits. Review only the commits after bf2ec8e57 (#1168's head): git diff bf2ec8e57..HEAD. It stays a draft until #1168 merges.

Full description, invariants and measurements to follow in this body.

axiom: n/a: telemetry infrastructure, no policy encoding

🤖 Generated with Claude Code

MaxGhenis and others added 12 commits October 9, 2026 10:33
Every concurrent build on a host shares one SQLite spool. When another
process held its write lock, a starting service's registration gave up
after SQLite's 5 s busy wait, the service exited and its SQLAlchemy
traceback landed on the build's stderr, so the build ran with no hosted
telemetry.

- The build passes its readiness deadline (--ready-deadline, Unix time)
  and the service retries SQLITE_BUSY/SQLITE_LOCKED during spool open and
  registration with jittered doubling backoff until 1 s before it. If the
  spool stays locked it prints one line and exits 75 (EX_TEMPFAIL); any
  other failure prints one line and exits 1.
- Opening a spool at head takes no write lock: retention pruning moved
  from spool open and every append to the delivery worker
  (prune_if_due, once per interval, failed attempts included).
- Migrations run in one BEGIN IMMEDIATE transaction after a read-only
  head check, so concurrent first opens no longer interleave DDL (23 of
  48 such opens failed with "table already exists" or a duplicate
  alembic_version row) and a failed migration leaves no partial schema.
- The delivery worker skips a failed step for one tick instead of dying:
  lock contention is silent and retried, other errors print one line per
  type, a failed heartbeat stays due, and the parent check that records
  a killed build keeps running.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
…ntained

From the design review of the first commit:

- Startup statements wait at most 0.25 s each in SQLite (a busy timeout
  applied per connection checkout), so the retry loop, not a 5 s busy
  wait, decides when to give up, and the service exits with its one-line
  reason before the build stops waiting (margin now 2 s). The wait is
  capped at 60 s whatever the deadline or the wall clock says; an
  infinite deadline is accepted and capped, NaN is refused.
- main opens and registers the spool (open_registered_spool), then
  restores the normal 5 s wait; EmitterService.run expects a registered
  producer.
- The client computes the deadline with datetime.now(UTC), the module's
  existing wall clock, so #1166's fake-clock startup tests keep passing
  once both land.
- prune deletes in batches of 500 rows, each in its own transaction, so
  the first prune in the worker never holds the write lock (or the lock
  the event path shares) for long.
- An unknown spool revision (a later migration from another checkout) is
  refused from the read-only check, without taking the write lock.
- Warnings go through write_warning, which never raises, so a closed
  stderr pipe cannot kill the worker; serving stops if the worker ever
  dies; an unexpected delivery error backs off like a collector failure
  instead of repeating every tick.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
The retry and classifier properties only sometimes generated the cases
that tell a correct implementation from a broken one: a wait crossing a
deadline 0.04 s away, a second retry, an extended SQLITE_BUSY code. Lock
errors and short attempts are now weighted up, busy and locked primaries
are drawn with every extension, and the boundary cases are explicit
examples. Threaded tests stop their service in a finally block and use
daemon threads, so a failing run cannot hang pytest at exit.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
The worker property reached the drain with failures left in its script
only some of the time, so an unguarded drain survived one of three fresh
Hypothesis runs. A dedicated property drives the drain directly: it never
raises, never runs past its deadline, and reports each error type once.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
From the in-session review:
- A build that sent close and exited while a worker step was running was
  recorded as an unexpected exit after its completion. The worker now
  checks the build only while it has not been closed (pre-existing).
- A parent check that raises is reported and treated as a dead build,
  so the worker never dies on it.
- Invalid arguments print one line (exit 2) instead of a usage block.
- The client passes --ready-deadline=<value> as one token, so a past or
  negative deadline parses.
- SIGINT ends the service at once, as SIGTERM does, instead of printing
  a KeyboardInterrupt traceback.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
The emitter service appended each event to the shared SQLite spool before
replying, so another build holding the spool's write lock stalled the
build's sends past the client's 0.2 s timeout and dropped events once
SQLite's 5 s busy wait ran out. The socket thread now validates an event,
queues it in a bounded in-memory queue and replies at once. One writer
thread appends queued events in order, in batches, retrying lock errors
for as long as they last. Heartbeats and the killed-build record use the
same queue. On close or parent death the service drains the queue within
its drain window and reports in one line anything it could not write.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
…d-only

From the in-session review: back-to-back prune batches still kept other
processes off the spool for the whole prune, because SQLite's busy handler
polls rather than queueing and rarely lands in the gap between two
transactions; another service's appends waited up to 5.2 s during a
100k-row prune. And the batched DELETEs took the write lock even when
nothing was due, where the old prune only read.

- prune pauses 25 ms between batches, outside the process lock, and
  works at most 1 s per worker tick; an unfinished prune resumes on the
  next tick instead of waiting the 60 s interval.
- prune checks read-only for expired events and expired runs before
  deleting, so an idle prune takes no write lock.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Keep #1168's clean-close check and guarded parent check in the worker,
with the killed-build record queued and the queue closed behind it.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
…ock-startup

# Conflicts:
#	packages/microcosm-build/src/microcosm/build/telemetry_emitter_service/collector.py
MaxGhenis and others added 6 commits October 9, 2026 19:53
main's #1147 and #1168 both changed the collector's denied-credential
warning: keep #1168's never-raising write_warning with #1147's per-reason
message. #1147 also adds a blocked run ending, which is a run event and so
uses the queue's reserved room; say so where the reserve is described.
Give the remaining Hypothesis properties no per-example deadline.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Startup, from the in-session review: with main's 3 s client budget the
2 s margin and 0.25 s SQLite waits made the service give up after about
1 s, where the old single 5 s busy wait rode out a 1.5 s hold. Now every
SQLite wait during startup ends by the startup deadline (0.5 s before
the build stops waiting) and lasts at most the normal 5 s; opening and
registering share one retry loop; and without --ready-deadline startup
makes one attempt with the normal wait, as before.

From the GPT-6.1 Sol review of bf2ec8e:
- A retry no longer starts after its deadline when the backoff sleep
  overruns.
- A build that closes within the worker's first tick still gets one
  bounded prune step, so short builds cannot skip retention forever.
- Expired runs are deleted in batches like events, and the size check
  reads the file's page counts before it sums every payload, so a spool
  under the cap is not scanned.
- The contention tests wait on observed attempts and thread state
  instead of fixed sleeps.

Tests, from the tests-and-claims lens: the classification check is
exhaustive with literal codes, the deadline property states behaviour
rather than the formula, the prune differential covers more expired
rows than one batch with no size pressure and an exact-fit cap, main()
runs under a timeout, the opener test waits for BEGIN IMMEDIATE, and
socket directories and service processes are cleaned up.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
…of hanging

A helper that read its deadline once kept retrying a spool that stayed
locked, and the test looped on its fake clock until an outer timeout.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Review of #1174 found four defects.

run() could return while the writer was still retrying, with events
unwritten and no warning: a drain flag recorded that a drain had begun,
not that it had finished, so a worker held up in a delivery step let
run() time out its join and leave. A hung worker instead earned a second
full window. One window now opens at the first stop signal, the writer
gets its deadline at once, and run() waits for the writer and reports
what it left before returning.

An append could touch the database after its cutoff: the cutoff was
checked once before the retry helper, so a deadline arriving during a
backoff, a backoff that overran, or a wait for this process's own spool
lock could each carry a write past it. Every attempt now checks once it
holds the spool, and waits a bounded time for it.

One busy timeout did not bound an append: it waited for the write lock
and again at COMMIT, 3.4 s against a 2 s timeout when measured. An
append's statements now share one lock-wait budget.

A long stage id, which the client does not limit, made the killed-build
record too large for the queue's reserved room. The service's copy of
the stage id is cut to the client's text limit.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
#1168 now re-checks the retry deadline after each backoff, in case the
sleep overran. Read the deadline through the callable there too: the
automatic merge compared the clock against the function itself. Its
worker also prunes once more before draining.

Model a wait for this process's own spool lock in the drain property,
state the retry property for a deadline read around every wait, and
keep the drain tests to the service's own stderr lines.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>

This branch has not been deployed

No deployments
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant