PR 10 — Operational enhancements - #30
Conversation
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
left a comment
There was a problem hiding this comment.
I found a couple of correctness edge cases worth tightening.
| # 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) |
There was a problem hiding this comment.
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? |
There was a problem hiding this comment.
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>
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 onlyHealthController,config/routes.rbwas six lines, and there was no/statusat all — the descope ladder's "basic status ships earlier" landed asbin/ingest's stdout block, not as an endpoint. Concretely:Github::Ingestion::StateSummaryandGithub::Enrichment::Summaryalready computed most of §11's content, but only for the CLI.ENRICHMENT_COVERAGE_WINDOW_SECONDSwas absent fromGithub::Configuration::DEFAULTS, and three places carried comments saying so until PR 10. No code anywhere joinedpush_eventstogithub_actors/github_repositories; this PR writes the first such query./api/push_eventsdid not exist, so §16's "raw payload is retained" and "both actor and repository enrichment demonstrably occur" gates were only checkable via psql.request_executor.rb:52slept silently,retry_policy.rbhad no log calls, and every HTTP failure detail was DEBUG-only whileconfig.log_leveldefaults toinfo— so a running system logged nothing about a 500, a timeout, or an SSRF rejection.Ingestion::PollState#record!wrote the terminal, operator-recoverable-onlystatus: "failed"transition with no log line at all.Scope
In:
GET /status;GET /api/push_eventsandGET /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); thegithub_id→ typed-key log rename and any sharedlog_eventhelper (unrelated cleanup, which CLAUDE.md forbids mixing in).Technical decisions
The coverage window is measured on
created_at, notoccurred_at. §11 defines the formulas but not the basis. Coverage grades this application's enrichment pipeline, and that pipeline's own eligibility rule is alreadyCOALESCE(last_seen_at, created_at)and its freshness rule isfetched_at + TTL— both our clock. §11's own wording is "distinct persisted push events in the coverage window". Decisive practical point: the fixture corpus pinsoccurred_atto a fixed date, so anoccurred_atbasis reports three nulls to anyone running the offline walkthrough after that date. Measured on a dev database: 4 events inside thecreated_atwindow, 0 inside theoccurred_atwindow. 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.rbalready states this repo's "no index until a query demands one" posture. Notecreated_at >= occurred_atalways, so theoccurred_atwindow 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 ascoverage.basisso the choice is reviewable from the response.One
Github::Status::Snapshotaggregate, notStateSummary.capture+Summary.captureside by side. Three parts of the response needgithub_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::Summarygained an optionalbudget:kwarg). A spec pins the single read. Rejected: reuse, which additionally runs an unboundedPushEvent.count§11 does not ask for, collapsesPollScheduleto one instant where §11 wants the components, and exposes neitherpoll_used,poll_allowancenorreserve.pending_actor_countmeans the status, andcandidatesis published beside it. §11 listspending_*next toskipped_*, andskipped_budgetis a status value — so its sibling is too.StateSummaryuses the same name for theenrichment_candidatesscope (pending plusretryable_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./statustherefore names all five statuses pluscandidates, and a spec asserts all three numbers together.Enrichment::Summarygainedclaimable_now.next_enrichment_atwasnilin two different states — work is claimable now, and nothing will ever become claimable — and#to_sprinted "due now" for both, sobin/enrichsaid work was due in the same breath it reported nothing to enrich. Publishing that same nil as JSON would hand every/statusconsumer the identical ambiguity. This is the one edit to PR 7 code; it rewrites one existing example into a pair.:idisgithub_event_id, and the surrogate PK appears in no response. Both are numeric strings, soGET /api/push_events/12is genuinely ambiguous and only one reading can be right. §11 putsgithub_event_idon 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 targetgithub_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=25after a poll lands re-serves page-1 rows and skips others. A spec reproduces exactly that. The seek predicate is written asoccurred_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 onlyindex_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+\zrather thanKernel#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=5would otherwise return the entire unfiltered feed while looking like a successful filtered response.ApplicationControllergained tworescue_fromhandlers. Not tidiness:consider_all_requests_localis true in test and development andapi_onlymakesdebug_exception_response_format:api, so an unrescuedRecordNotFoundrenders as JSON carrying the exception class and its full backtrace.HealthControlleralready refuses to leak that way.Failed requests are raised to
warn; successful ones stay atdebug. §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, andconfig.log_leveldefaults toinfo. Deliberately not promoted:budget_deniedandgate_unavailable(nothing spent, and the caller logs its own deferral),rate_limitedandsecondary_limited(their INFO line isbudget.global_block_set, once per block rather than once per request). One event name across both levels, sogrep github.requestkeeps meaning "every request".PollStatelogs its own terminal transition, rather thanIngestionRunnerdoing it. Its entity-side mirrorEnrichment::EntityStatealready logs three of its own anomalies;PollStateis not a pure calculator (it issuesupdate!); the runner would have to re-derive the predicate, and two readers of one rule is drift waiting to happen; and onlyPollStateknows the delay. It logs from the written attributes, after the UPDATE, so a future second path tofailedis reported without anyone remembering to extend it.Rejected: a shared
log_eventhelper. 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 byJsonLogFormatter), no home without new infrastructure, and it would force a second 12-file spec rewrite.ApplicationJob#log_contextis 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_statusandfetched_at, which is what makes §16's enrichment gate visible in a browser)./api/ingestion_runswould need anindex_ingestion_runs_on_started_atmigration — schema work inside an observability PR — and/statusalready reports the latest run per source.Testing performed
1500 examples, 0 failures. RuboCop clean across 217 files; Brakeman
--exit-on-warnreports 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:
/statusand the inspection endpoints, extending the pair that already pinsStateSummary: a recording transport that must see no request;not_to change(GithubApiBudget, :count)— which catches the subtle mistake of reachingBudgetLedger#bootstrap!from a read path;not_to change(EventSource, :count)— theSourceProvisionermirror of it; and a newsql.active_recordsubscriber (spec/support/sql_helpers.rb) that fails on anyINSERT/UPDATE/DELETE, so a future collaborator cannot introduce a write silently.pendingvscandidates, asserting/status's number,enrichment_candidates.countandStateSummary#pending_actor_countin one example.:idis not the PK — the surrogate key 404s, the GitHub event id 200s.limit=1and forlimit=50.Linkheader round-trips through this application's ownGithub::LinkHeaderparser.transient_failure_exhaustedcorpus scenario: twogithub.retry_scheduledat info, onegithub.retry_exhaustedat warn, threegithub.requestat warn, andingestion.source_backoff— all carrying the samerun_id.Docker verification
bin/ingestandbin/enrichsmokes both green in fixture mode (both arebin/cisteps and theEnrichment::Summary#to_schange 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: 3of 4 →75.0. The two incomplete entities are the corpus's deliberateghostuser/deleted-org/gone404s.actor_requests.used + repository_requests.used == enrichment.used.claimable_now: falsewithnext_enrichment_at24h out — the drained-backlog state that used to print "due now".GET /api/push_events?limit=2— rows nest both entities; one showsenrichment_status: "complete"with afetched_at, the otherpermanent_failurewithfetched_at: null.Link: <…?cursor=…&limit=1>; rel="next"present and well-formed.GET /api/push_events/58000000008returnsraw_payloadwith the full envelope keys.?limit=99999→ 400,?repo_id=5→ 400,/nope→ 404,?cursor=zzz→ 400, each with the documented body./statussendsCache-Control: no-store.Documentation updates
README.md— the two new endpoint sections (including the three response conventions:nullis never a zero, thecreated_atbasis, andavailableis a floor not a ceiling), the expanded "What a run logs", and theLOG_LEVELrow rewritten now that failures reach the default level..env.exampleanddocker-compose.yml—ENRICHMENT_COVERAGE_WINDOW_SECONDSmoved 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 inconfiguration.rb,enrichment/summary.rbandingestion/state_summary.rb, all three of which said this work was deferred to PR 10.No
IMPLEMENTATION_PLAN.mdamendment: 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_atis 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.(occurred_at, id)index, so the keyset seek relies on theoccurred_atrange predicate plus a cheap recheck.EXPLAINwas not run at scale; the follow-up is one migration plus a rewrite to the row-value form.Started GET … / Completed 200 OKlines still flow throughJsonLogFormatteras{"message": "…"}for the three new routes, as they already do for/health/ready.config.silence_healthcheck_pathtakes a single path, and lograge is a new dependency the plan does not sanction — noted for PR 12 rather than fixed here./statusissues ~12 statements, the slowest beingCandidateSelector#earliest_refresh_at'sMIN(GREATEST(fetched_at + interval, next_retry_at)), which cannot use an index. It is the same costbin/enrichalready pays and is only reached when nothing is claimable.COUNT(*)on an append-only table is a sequential scan per request, and §11 already assigns "persisted push events" to/status.🤖 Generated with Claude Code