Skip to content

PR 10 — Operational enhancements - #30

Merged
batbrainy merged 2 commits into
mainfrom
pr-10-operational-enhancements
Jul 31, 2026
Merged

PR 10 — Operational enhancements#30
batbrainy merged 2 commits into
mainfrom
pr-10-operational-enhancements

Conversation

@batbrainy

Copy link
Copy Markdown
Owner

Linked issue

Closes #20 — maps to IMPLEMENTATION_PLAN.md §13, "PR 10 — Operational enhancements".

Problem

§13 assigns PR 10 three capabilities and none existed. app/controllers/ held only HealthController, config/routes.rb was six lines, and there was no /status at all — the descope ladder's "basic status ships earlier" landed as bin/ingest's stdout block, not as an endpoint. Concretely:

  • No HTTP surface for state. Github::Ingestion::StateSummary and Github::Enrichment::Summary already computed most of §11's content, but only for the CLI.
  • The coverage percentages had never been computed. ENRICHMENT_COVERAGE_WINDOW_SECONDS was absent from Github::Configuration::DEFAULTS, and three places carried comments saying so until PR 10. No code anywhere joined push_events to github_actors/github_repositories; this PR writes the first such query.
  • /api/push_events did not exist, so §16's "raw payload is retained" and "both actor and repository enrichment demonstrably occur" gates were only checkable via psql.
  • "Retry scheduled" was the one INFO event §11 names by name with zero implementation. request_executor.rb:52 slept silently, retry_policy.rb had no log calls, and every HTTP failure detail was DEBUG-only while config.log_level defaults to info — so a running system logged nothing about a 500, a timeout, or an SSRF rejection. Ingestion::PollState#record! wrote the terminal, operator-recoverable-only status: "failed" transition with no log line at all.

Scope

In: GET /status; GET /api/push_events and GET /api/push_events/:id; six failure/retry logging changes.

Deliberately out: /api/actors/:id, /api/repositories/:id, /api/ingestion_runs (§11 marks all three "Optional" — see below); crash-window and multi-poller stress tests (PR 11); README completion and the architecture diagram (PR 12); the github_id → typed-key log rename and any shared log_event helper (unrelated cleanup, which CLAUDE.md forbids mixing in).

Technical decisions

The coverage window is measured on created_at, not occurred_at. §11 defines the formulas but not the basis. Coverage grades this application's enrichment pipeline, and that pipeline's own eligibility rule is already COALESCE(last_seen_at, created_at) and its freshness rule is fetched_at + TTL — both our clock. §11's own wording is "distinct persisted push events in the coverage window". Decisive practical point: the fixture corpus pins occurred_at to a fixed date, so an occurred_at basis reports three nulls to anyone running the offline walkthrough after that date. Measured on a dev database: 4 events inside the created_at window, 0 inside the occurred_at window. Rejected: occurred_at, whose merit is the existing index. The cost of not using it is a sequential scan, accepted deliberately — spec/db/schema_spec.rb already states this repo's "no index until a query demands one" posture. Note created_at >= occurred_at always, so the occurred_at window is a strict subset whose dropped rows are exactly the high-latency catch-up events — removing them from the denominator alone would inflate the reported percentage. The basis is published as coverage.basis so the choice is reviewable from the response.

One Github::Status::Snapshot aggregate, not StateSummary.capture + Summary.capture side by side. Three parts of the response need github_api_budget; composing the two existing summaries would read the singleton three times, so a reservation committing mid-request could produce one body whose poll block contradicts its ledger block. The snapshot reads it once and passes it down (Enrichment::Summary gained an optional budget: kwarg). A spec pins the single read. Rejected: reuse, which additionally runs an unbounded PushEvent.count §11 does not ask for, collapses PollSchedule to one instant where §11 wants the components, and exposes neither poll_used, poll_allowance nor reserve.

pending_actor_count means the status, and candidates is published beside it. §11 lists pending_* next to skipped_*, and skipped_budget is a status value — so its sibling is too. StateSummary uses the same name for the enrichment_candidates scope (pending plus retryable_failure), which is the right answer to "how much work is left". Both are correct for their own question; publishing one under a name the other also uses is how two numbers silently become one. /status therefore names all five statuses plus candidates, and a spec asserts all three numbers together.

Enrichment::Summary gained claimable_now. next_enrichment_at was nil in two different states — work is claimable now, and nothing will ever become claimable — and #to_s printed "due now" for both, so bin/enrich said work was due in the same breath it reported nothing to enrich. Publishing that same nil as JSON would hand every /status consumer the identical ambiguity. This is the one edit to PR 7 code; it rewrites one existing example into a pair.

:id is github_event_id, and the surrogate PK appears in no response. Both are numeric strings, so GET /api/push_events/12 is genuinely ambiguous and only one reading can be right. §11 puts github_event_id on every log line — the point of an inspection endpoint is getting from a log line to a record — it is the unique index the idempotency story rests on, and this schema already refuses to make surrogate keys identity (the FKs target github_id). The surrogate key survives only inside the opaque cursor, which is why the cursor is opaque.

Keyset pagination on (occurred_at, id), not offset. Offset is demonstrably wrong here, not theoretically: the poller writes continuously and the list is newest-first, so ?offset=25 after a poll lands re-serves page-1 rows and skips others. A spec reproduces exactly that. The seek predicate is written as occurred_at <= ? AND (occurred_at < ? OR id < ?) rather than the row-value form — PostgreSQL only pushes a row comparison into an index when a matching multicolumn index exists, and this schema has only index_push_events_on_occurred_at, so the row-value form would degrade to a filter over a full scan.

Invalid parameters are 400, never a silent clamp. A client that asked for 500 and received 100 cannot tell whether it received everything. Parsing is \A\d+\z rather than Kernel#Integer, which reads "010" as 8 and "0x10" as 22 — three query strings would otherwise mean something other than what they read as. Unknown parameters are refused too: ?repo_id=5 would otherwise return the entire unfiltered feed while looking like a successful filtered response.

ApplicationController gained two rescue_from handlers. Not tidiness: consider_all_requests_local is true in test and development and api_only makes debug_exception_response_format :api, so an unrescued RecordNotFound renders as JSON carrying the exception class and its full backtrace. HealthController already refuses to leak that way.

Failed requests are raised to warn; successful ones stay at debug. §11 puts per-request lines at DEBUG, which is right for the ones that worked — but §11 also sizes the INFO stream so the events Story 4 asks reviewers to see are in it, and config.log_level defaults to info. Deliberately not promoted: budget_denied and gate_unavailable (nothing spent, and the caller logs its own deferral), rate_limited and secondary_limited (their INFO line is budget.global_block_set, once per block rather than once per request). One event name across both levels, so grep github.request keeps meaning "every request".

PollState logs its own terminal transition, rather than IngestionRunner doing it. Its entity-side mirror Enrichment::EntityState already logs three of its own anomalies; PollState is not a pure calculator (it issues update!); the runner would have to re-derive the predicate, and two readers of one rule is drift waiting to happen; and only PollState knows the delay. It logs from the written attributes, after the UPDATE, so a future second path to failed is reported without anyone remembering to extend it.

Rejected: a shared log_event helper. 39 call sites, a 39-hunk diff inside a 6-event PR, no behaviour to add (the four universal fields are already owned and un-spoofable by JsonLogFormatter), no home without new infrastructure, and it would force a second 12-file spec rewrite. ApplicationJob#log_context is the only bundle that clears that bar and already exists.

Rejected: the three optional endpoints. The entity endpoints would only re-render data already nested in the push-event responses (including enrichment_status and fetched_at, which is what makes §16's enrichment gate visible in a browser). /api/ingestion_runs would need an index_ingestion_runs_on_started_at migration — schema work inside an observability PR — and /status already reports the latest run per source.

Testing performed

1500 examples, 0 failures. RuboCop clean across 217 files; Brakeman --exit-on-warn reports 0 warnings.

New: spec/services/github/enrichment/coverage_spec.rb, spec/services/github/status/snapshot_spec.rb, spec/requests/status_spec.rb, spec/services/inspection/{cursor,push_event_page,push_event_view}_spec.rb, spec/requests/api/push_events_spec.rb, plus new blocks in the request-executor, poll-state, enrichment-runner and ingestion-runner specs.

The examples worth reviewing:

  • Four structural guarantees on both /status and the inspection endpoints, extending the pair that already pins StateSummary: a recording transport that must see no request; not_to change(GithubApiBudget, :count) — which catches the subtle mistake of reaching BudgetLedger#bootstrap! from a read path; not_to change(EventSource, :count) — the SourceProvisioner mirror of it; and a new sql.active_record subscriber (spec/support/sql_helpers.rb) that fails on any INSERT/UPDATE/DELETE, so a future collaborator cannot introduce a write silently.
  • Two basis-discriminating coverage examples — an event that occurred outside but was persisted inside the window is counted, and the converse is not. Each alone would pass under either basis; together they pin the decision.
  • pending vs candidates, asserting /status's number, enrichment_candidates.count and StateSummary#pending_actor_count in one example.
  • Insert-during-paging, which is the concrete justification for keyset over offset.
  • :id is not the PK — the surrogate key 404s, the GitHub event id 200s.
  • Statement count is a function of page shape, not page size — 3 SELECTs for limit=1 and for limit=50.
  • The Link header round-trips through this application's own Github::LinkHeader parser.
  • The whole retry ladder end to end against the transient_failure_exhausted corpus scenario: two github.retry_scheduled at info, one github.retry_exhausted at warn, three github.request at warn, and ingestion.source_backoff — all carrying the same run_id.
  • Retry exhaustion vs. never-retryable: a permanent 404 emits no exhaustion line, which is what keeps the line meaningful.

Docker verification

bin/ingest and bin/enrich smokes both green in fixture mode (both are bin/ci steps and the Enrichment::Summary#to_s change touches them). Then booted Puma against the fixture corpus and exercised every endpoint:

  • GET /status — 4 events, 3 actors / 2 complete → actor_coverage_pct: 66.67; 3 repos / 2 complete → 66.67; both_complete_event_count: 3 of 4 → 75.0. The two incomplete entities are the corpus's deliberate ghostuser / deleted-org/gone 404s. actor_requests.used + repository_requests.used == enrichment.used. claimable_now: false with next_enrichment_at 24h out — the drained-backlog state that used to print "due now".
  • GET /api/push_events?limit=2 — rows nest both entities; one shows enrichment_status: "complete" with a fetched_at, the other permanent_failure with fetched_at: null.
  • Link: <…?cursor=…&limit=1>; rel="next" present and well-formed.
  • GET /api/push_events/58000000008 returns raw_payload with the full envelope keys.
  • ?limit=99999 → 400, ?repo_id=5 → 400, /nope → 404, ?cursor=zzz → 400, each with the documented body.
  • /status sends Cache-Control: no-store.

Documentation updates

README.md — the two new endpoint sections (including the three response conventions: null is never a zero, the created_at basis, and available is a floor not a ceiling), the expanded "What a run logs", and the LOG_LEVEL row rewritten now that failures reach the default level. .env.example and docker-compose.ymlENRICHMENT_COVERAGE_WINDOW_SECONDS moved out of the "Deliberately absent" block into the enrichment timings, with the shared-anchor note that it is a report input rather than a policy input. Stale comments corrected in configuration.rb, enrichment/summary.rb and ingestion/state_summary.rb, all three of which said this work was deferred to PR 10.

No IMPLEMENTATION_PLAN.md amendment: every event added is already required by §11's INFO list or §16's Operability gates, which was the scoping test each inclusion had to pass. No new ADR — no architectural direction changes.

Known limitations

  • created_at is unindexed, so the coverage query is a sequential scan. At the pinned defaults that is on the order of 3,000 rows/day, so a month is under 100k rows. The fix, if volume ever demands it, is a one-line migration.
  • No composite (occurred_at, id) index, so the keyset seek relies on the occurred_at range predicate plus a cheap recheck. EXPLAIN was not run at scale; the follow-up is one migration plus a rewrite to the row-value form.
  • Rails' own unstructured Started GET … / Completed 200 OK lines still flow through JsonLogFormatter as {"message": "…"} for the three new routes, as they already do for /health/ready. config.silence_healthcheck_path takes a single path, and lograge is a new dependency the plan does not sanction — noted for PR 12 rather than fixed here.
  • /status issues ~12 statements, the slowest being CandidateSelector#earliest_refresh_at's MIN(GREATEST(fetched_at + interval, next_retry_at)), which cannot use an index. It is the same cost bin/enrich already pays and is only reached when nothing is claimable.
  • No total count on the list endpointCOUNT(*) on an append-only table is a sequential scan per request, and §11 already assigns "persisted push events" to /status.

🤖 Generated with Claude Code

Rich GET /status, the event inspection API, and extended failure and retry
logging (IMPLEMENTATION_PLAN.md §11, §13).

Closes #20

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>

@batbrainy batbrainy left a comment

Copy link
Copy Markdown
Owner Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I found a couple of correctness edge cases worth tightening.

Comment thread app/services/github/status/snapshot.rb Outdated
# Matches IngestionRun.latest_successful's definition of success, which includes a
# 304: the poll succeeded and GitHub reported nothing new.
def self.latest_runs
IngestionRun.successful.where.not(completed_at: nil)

Copy link
Copy Markdown
Owner Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Can this use the latest completed run, not only successful ones? The plan says /status reports the source's "last run", and with this filter a fresh failed or deferred run is hidden behind an older 200/304. That leaves an operator seeing a stale healthy last_run while the source may have just failed or backed off. If the intent is specifically "latest successful", the field name should probably say that.

def parse_github_id(name, value)
return nil if value.blank?

unless value.to_s.match?(DECIMAL) && value.to_i.positive?

Copy link
Copy Markdown
Owner Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This validates shape and positivity, but not the database range. github_actor_id and github_repository_id are signed bigints, so a request like ?actor_id=999999999999999999999999 can get past this parser and fail later in PostgreSQL instead of returning the documented 400. The cursor's embedded row id has the same issue. Can we cap these parsed ids to the bigint range before using them in the query?

/status reported only successful runs under a field named last_run, hiding a
fresh failure behind an older 200 or 304. Report the latest finished run of any
status; `running` stays excluded, having reached no outcome.

Parsed GitHub ids and cursor positions were shape-checked but not range-checked
against the bigint and timestamp bounds they are bound to. Verified against
PostgreSQL 16: a raw bind past those bounds raises (500), while a typed-column
bind is cast silently and returns a wrong answer. Both now return the documented
400.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
@batbrainy
batbrainy merged commit 5454dda into main Jul 31, 2026
2 checks passed
@batbrainy
batbrainy deleted the pr-10-operational-enhancements branch July 31, 2026 02:49
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.

PR 10 — Operational enhancements

1 participant