Overview
Agentic sourcing runs several boolean resume-search queries in parallel. A leg that fails is swallowed into an empty result so the surviving legs still return candidates — which means a degraded search looks exactly like a small candidate pool. A 166-second query hid behind this for a long time.Metric
sourcing.boolean_search.query_legs — count, emitted per outcome bucket per search from
server/sourcing/boolean_search_observability.py.
outcome:ok is emitted even at zero — it anchors the denominator, since a ratio monitor
grouped by org drops any group missing from either side of the arithmetic. Do not alert on
untranslatable: it measures LLM query quality, not database health.
Do not alert on aborted or early_stopped either, and keep them out of the denominator. When a full
concurrency wave has done nothing but time out, the remaining legs are skipped rather than
spending one statement timeout each to reach the same answer, since legs of one search share
the org, the scope and the filters. Similarly, when a batch of queries has already accumulated
enough unique candidates to reach the target, remaining batches are skipped. Those legs never
ran, so counting them in the denominator would dilute the failure rate. The timeouts that stopped the
fan-out are still counted as failed, and they are what the alert should fire on.
Leg timing metrics
Added alongsidequery_legs so a leg’s cost is measurable rather than inferred from wall-clock
logs. All three come from the same emission point and carry the same caller / org_id tags,
so they divide by query_legs directly.
Seconds are summed per search and submitted as counts, not per-leg gauges: the metric
submitter stamps one point per call at whole-second resolution, so two legs of one search sharing
a tag set would overwrite each other. Counts add instead.
candidate_resumes.
leg_wait_seconds_total is what says whether that queueing is costing anything: near-zero means
searches rarely overlap, and a rise there paired with a fall in leg_seconds_total{outcome:ok}
and in query_legs{outcome:failed} is the intended trade working. The cap is process-local, so
N replicas can each run up to the cap.
Per-leg detail (the shape percentiles need, which counts and gauges cannot express) is in the
logs: [BOOLEAN_LEG] leg i/n outcome=… wait=…s duration=…s, bound with org_id and caller.
One line per leg that reached the fan-out, including untranslatable, early-stopped, and aborted ones, so the
line count matches n. Filter to outcome:ok before taking percentiles — a leg that never
reached Postgres reports zeros, and a timed-out leg reports the full statement timeout, so both
skew a healthy-leg distribution in opposite directions. The log outcomes are the same five the
counts use, and an aborted or early-stopped leg contributes nothing to any timing total, including the queue
wait: it did sit in the queue (or was never queued), but reporting that would be time spent waiting to run a
statement that was then never run.
The sourcing-mode intake prefetch is not behind the slot, so its leg_wait_seconds_total is
always zero. Its fan-out is already bounded and runs under a 45s budget shorter than a single
cold leg, so queueing it would push it into that timeout.
Suggested monitor
Not yet created — set the threshold against a post-#8523 baseline rather than guessing. Before that fix the failure rate was 23% over 7 days.ATS request queue failure rate > 5% (monitor 309673813): clamp_min avoids
divide-by-zero and is_greater(…, 19) stops an org doing under 20 legs/hour paging on one
unlucky timeout. Use notification_preset_name: hide_query_and_handles and a one-line message
linking here, per ATS Sync Alerts.
What to check when it fires
- One org or many? Many points at the database; one points at that org’s corpus or query shape.
- Which failure kind? Group
"failed during boolean resume search"by@error.kind.DBAPIErroris the statement timeout;ProgrammingErroris a malformed tsquery reaching execute time and is not a database-health signal. - Did the scope reach the index condition? Run
python -m one-time-jobs.explain_boolean_fts_leg --org-id <org> --tsquery '<tsquery>' --lat <lat> --lon <lon> --radius-miles <r> --exclude-contacted-days <n> --compare. It plans the real statement with the scope array bound and prints whether the scope landed in the index condition or as a post-recheck filter. The second is the pathology this whole page exists for: the planner underestimates the GIN side by orders of magnitude, decides a scope bitmap is not worth intersecting, and the leg then detoasts every row the index returns. A leg with a usable scope should be running two statements (look forBoolean FTS phase 1 matched N candidate idsin the logs up toBOOLEAN_SEARCH_RANK_BUDGETof 5,000); if the candidate ID count exceeds the budget, it logsBoolean FTS phase 1 matched more than 5000 candidate ids for tsquery ...; ranking the 5000 most recently updated of them. A leg without a usable scope runs the single statement and is inherently slower. - Did the bitmap go lossy?
EXPLAIN (ANALYZE, BUFFERS)and readHeap Blocks: exact=N lossy=Mon thecandidate_resumesscan. Anylossymeans the scan is rechecking every tuple on those pages and detoasting a ~10KB tsvector for each.work_memfor this statement is set viaBOOLEAN_SEARCH_WORK_MEM_MBinsearch_resume_text_boolean. - Know the floor. Phrase queries (
<->) force a GIN recheck because the index stores no lexeme positions, so a large org on a broad phrase query is inherently slow. The question is whether it got slower.
What recruiters see
Depends on which query failed. A scope-prefetch statement timeout is visible. The prefetch computes the org / consent / geo / age scope once per tool call. When it times out, the search stops and the recruiter gets afatal_error event from streaming_controller.py. It fails rather than falling back because
the fallback rebuilds that same scope as a CTE inside every leg, which is strictly more work
than the query that just ran out of time. Any other prefetch failure still falls back to the
CTE plan silently, since those are recoverable.
Individual leg failures are still silent. A leg that times out is swallowed into an empty
result so the surviving legs still return candidates, which is what makes a degraded search look
like a small candidate pool. degraded_query_count / total_query_count flow through the result
models and the LLM is told per-query, but no UI affordance surfaces a partial search — at the
pre-fix failure rate a notice would have fired on most searches. The typed fields are in place,
so adding it later is small.