Skip to main content
Restricted Access: This documentation is only accessible to @tenzo.ai and @salv.ai email addresses.

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 alongside query_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.
The leg cap is shared across every agentic search in a worker process, so overlapping searches queue against each other instead of multiplying the statements aimed at 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.
Mirrors 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

  1. One org or many? Many points at the database; one points at that org’s corpus or query shape.
  2. Which failure kind? Group "failed during boolean resume search" by @error.kind. DBAPIError is the statement timeout; ProgrammingError is a malformed tsquery reaching execute time and is not a database-health signal.
  3. 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 for Boolean FTS phase 1 matched N candidate ids in the logs up to BOOLEAN_SEARCH_RANK_BUDGET of 5,000); if the candidate ID count exceeds the budget, it logs Boolean 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.
  4. Did the bitmap go lossy? EXPLAIN (ANALYZE, BUFFERS) and read Heap Blocks: exact=N lossy=M on the candidate_resumes scan. Any lossy means the scan is rechecking every tuple on those pages and detoasting a ~10KB tsvector for each. work_mem for this statement is set via BOOLEAN_SEARCH_WORK_MEM_MB in search_resume_text_boolean.
  5. 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 a fatal_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.