Skip to content

Commit 8589970

Browse files
Make posting CDC commit-order safe (#6049)
1 parent 7cbf905 commit 8589970

19 files changed

Lines changed: 768 additions & 40 deletions

.github/workflows/ci.yml

Lines changed: 44 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -495,6 +495,50 @@ jobs:
495495
- run: uv run pytest tests/e2e/test_typesense_indexing.py -v
496496
working-directory: apps/crawler
497497

498+
test-crawler-postgres-cdc-e2e:
499+
name: Test Crawler PostgreSQL CDC E2E
500+
needs: changes
501+
if: needs.changes.outputs.code == 'true'
502+
runs-on: ubuntu-latest
503+
services:
504+
postgres:
505+
image: postgres:16-alpine
506+
ports:
507+
- 5432:5432
508+
env:
509+
POSTGRES_USER: crawler
510+
POSTGRES_PASSWORD: crawler
511+
POSTGRES_DB: crawler
512+
options: >-
513+
--health-cmd "pg_isready -U crawler -d crawler"
514+
--health-interval 5s
515+
--health-timeout 5s
516+
--health-retries 12
517+
env:
518+
LOCAL_DATABASE_URL: postgresql://crawler:crawler@localhost:5432/crawler
519+
REQUIRE_POSTGRES_E2E: "true"
520+
steps:
521+
- uses: actions/checkout@3d3c42e5aac5ba805825da76410c181273ba90b1 # v7.0.1
522+
523+
- uses: astral-sh/setup-uv@c771a70e6277c0a99b617c7a806ffedaca235ff9 # v9.0.0
524+
with:
525+
enable-cache: true
526+
prune-cache: true
527+
cache-dependency-glob: "apps/crawler/uv.lock"
528+
529+
- uses: actions/setup-python@5fda3b95a4ea91299a34e894583c3862153e4b97 # v7.0.0
530+
with:
531+
python-version: "3.13"
532+
533+
- run: uv sync --group dev
534+
working-directory: apps/crawler
535+
536+
- run: uv run alembic -c src/migrations/alembic.ini upgrade head
537+
working-directory: apps/crawler
538+
539+
- run: uv run pytest tests/e2e/test_postgres_cdc_commit_order.py -v
540+
working-directory: apps/crawler
541+
498542
coverage-crawler:
499543
name: Coverage Crawler
500544
needs: changes

AGENTS.md

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -201,7 +201,7 @@ cd apps/crawler && uv run python ../../scripts/typesense-backfill-local.py [--li
201201

202202
### Indexing Pipeline
203203

204-
- **Exporter** (CDC): two-cursor design — Supabase and Typesense cursors advance independently. Concurrent upserts via `asyncio.gather`
204+
- **Exporter** (CDC): database-triggered shared writer barrier + brief exclusive cutoff prevents commit-order skips; Supabase and Typesense cursors advance independently; concurrent upserts via `asyncio.gather`
205205
- **Sync**: taxonomy collections (location, occupation, seniority, technology) and the `company` collection populated after CSV sync. Company docs include extended fields (logo, website, employee_count_range, founded_year) and per-locale variants (`description_{de,fr,it}`, `industry_name_{de,fr,it}`) for the company detail page reader. Handles taxonomy rename detection
206206
- **Reconciliation**: daily count check + sample comparison
207207
- **refresh-typesense**: periodic count refresh for taxonomy/company collections + watchlist reconciliation. Runs inline at every deploy/CSV sync (via `crawler sync`) and every 4h via `.github/workflows/crawler-scheduled-maintenance.yml` out-of-band

apps/crawler/AGENTS.md

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -66,7 +66,7 @@ src/
6666
│ └── lookups.py # Cached lookup table loaders (locations, technologies, etc.)
6767
├── redis_queue.py # Lua-backed claim/enqueue/reschedule
6868
├── lua/ # claim_work.lua, enqueue_task.lua, reschedule_task.lua
69-
├── exporter.py # CDC: local Postgres -> Supabase + Typesense (two-cursor)
69+
├── exporter.py # Commit-safe CDC: local Postgres -> Supabase + Typesense (two-cursor)
7070
├── typesense_client.py # Shared Typesense client (lazy init, None when unconfigured)
7171
├── sync.py # CSV -> local Postgres + Supabase + Redis + Typesense taxonomies
7272
├── bootstrap.py # One-time: Supabase -> local Postgres copy

apps/crawler/VERSION

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1 +1 @@
1-
0.13.180
1+
0.13.181

apps/crawler/alerts.yaml

Lines changed: 42 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -473,6 +473,48 @@ groups:
473473
Export Lag panel.
474474
runbook: https://github.com/colophon-group/jobseek/blob/main/docs/03-crawler-architecture.md
475475

476+
# A timeout means at least one posting writer held its transaction open
477+
# beyond the barrier's bounded 120s wait. The exporter deliberately did
478+
# not choose a cutoff or advance either cursor, preserving data at the
479+
# cost of freshness. Route the root signal to the daily Codex review.
480+
- alert: CdcWriterBarrierTimeout
481+
expr: increase(crawler_exporter_cdc_barrier_timeouts_total{instance="exporter"}[15m]) > 0
482+
for: 1m
483+
labels:
484+
severity: high
485+
service: crawler
486+
owner: codex-error-review
487+
route: codex-daily
488+
annotations:
489+
summary: "CDC writer barrier timed out"
490+
description: |
491+
The exporter could not establish a commit-safe posting cutoff
492+
within 120 seconds. It kept both cursors pinned. Inspect
493+
`pg_stat_activity` for a long transaction and the
494+
`cdc_snapshot_barrier.timeout` exporter event before terminating
495+
anything.
496+
runbook: https://github.com/colophon-group/jobseek/blob/main/docs/03-crawler-architecture.md#commit-safe-posting-cdc
497+
498+
# The daily sample reconciliation now has an explicit alert path rather
499+
# than only a log line. Any discrepancy is actionable evidence that a
500+
# downstream missed or diverged from local authoritative state.
501+
- alert: CdcReconciliationDrift
502+
expr: increase(crawler_reconciliation_discrepancies_total{instance="exporter"}[25h]) > 0
503+
for: 5m
504+
labels:
505+
severity: high
506+
service: crawler
507+
owner: codex-error-review
508+
route: codex-daily
509+
annotations:
510+
summary: "Posting reconciliation found downstream drift"
511+
description: |
512+
The daily local PostgreSQL comparison found at least one missing
513+
or divergent Supabase/Typesense row. The reconciler touched the
514+
sampled rows for idempotent replay; confirm cursor health and run
515+
the exact reconciliation procedure before closing the incident.
516+
runbook: https://github.com/colophon-group/jobseek/blob/main/docs/03-crawler-architecture.md#commit-safe-posting-cdc
517+
476518
# Catches steady-state degradation: WAF blocking a major board
477519
# source, Postgres going read-only, etc. >50% failure rate is
478520
# rare in normal operation; legitimate noisy boards top out

apps/crawler/deploy.sh

Lines changed: 9 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -361,6 +361,15 @@ pull_deploy_images
361361

362362
docker compose up -d redis
363363

364+
# ── Quiesce every local-Postgres writer before schema cutover ──────
365+
# Migrations may introduce a database/runtime protocol (for example the
366+
# shared-writer/exclusive-exporter CDC barrier). Stop both sides before
367+
# Alembic so no old process can write or advance a cursor in the interval
368+
# between the schema change and the new containers starting. `--timeout 60`
369+
# matches the app's 30s bounded drain with headroom before Docker sends
370+
# SIGKILL. Redis and Alloy remain available throughout.
371+
docker compose stop --timeout 60 worker-1 worker-2 worker-3 browser-1 exporter drain
372+
364373
# ── Run Alembic migrations on local Postgres ─────────────────────────
365374
docker run --rm --env-file "$ENV_FILE" --network host \
366375
"ghcr.io/${OWNER}/jobseek-crawler:${IMAGE_TAG}" \
@@ -373,13 +382,6 @@ docker run --rm --env-file "$ENV_FILE" --network host \
373382
"ghcr.io/${OWNER}/jobseek-crawler:${IMAGE_TAG}" \
374383
uv run --no-sync crawler setup-typesense
375384

376-
# ── Quiesce processors before reseeding Redis-backed schedules ───────
377-
# Keep Redis and alloy up, but stop processors so deploy-time
378-
# `crawler sync` does not race with live workers claiming work while we
379-
# reseed board monitors. `--timeout 60` matches the app's 30s bounded
380-
# drain with headroom before Docker sends SIGKILL.
381-
docker compose stop --timeout 60 worker-1 worker-2 worker-3 browser-1 exporter drain
382-
383385
# ── Sync board config from CSV → local Postgres + Redis + Typesense ──
384386
docker run --rm --env-file "$ENV_FILE" --network host \
385387
"ghcr.io/${OWNER}/jobseek-crawler:${IMAGE_TAG}" \

apps/crawler/src/export_cursor_fence.py

Lines changed: 95 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -12,12 +12,15 @@
1212

1313
import asyncio
1414
import time
15-
from collections.abc import AsyncIterator, Callable
15+
from collections.abc import AsyncIterator, Awaitable, Callable
1616
from contextlib import AbstractAsyncContextManager, asynccontextmanager
17+
from datetime import datetime
1718

1819
import asyncpg
1920
import structlog
2021

22+
from src.metrics import exporter_cdc_barrier_timeouts, exporter_cdc_barrier_wait
23+
2124
log = structlog.get_logger()
2225

2326
# Stable, repository-owned bigint (ASCII-ish ``JOBSEEK``) shared by the
@@ -28,7 +31,19 @@
2831
_TRY_LOCK_SQL = "SELECT pg_try_advisory_lock($1::bigint)"
2932
_UNLOCK_SQL = "SELECT pg_advisory_unlock($1::bigint)"
3033

34+
# Distinct from the long operator-repair fence above. Every transaction that
35+
# changes an exported job_posting field takes the shared side from a database
36+
# trigger; the exporter briefly takes the exclusive side before choosing its
37+
# cutoff. ASCII-ish ``CDCLOCK`` encoded as a positive bigint.
38+
CDC_WRITER_BARRIER_ID = 0x4344434C4F434B
39+
_CDC_TRY_LOCK_SQL = "SELECT pg_try_advisory_lock($1::bigint)"
40+
_CDC_CUTOFF_SQL = "SELECT clock_timestamp()"
41+
_CDC_LOCK_TIMEOUT_SECONDS = 120.0
42+
_CDC_LOCK_RETRY_SECONDS = 0.1
43+
_CDC_SLOW_WAIT_SECONDS = 1.0
44+
3145
CursorFenceFactory = Callable[[asyncpg.Pool], AbstractAsyncContextManager[None]]
46+
CutoffFactory = Callable[[asyncpg.Pool], Awaitable[datetime]]
3247

3348

3449
@asynccontextmanager
@@ -86,3 +101,82 @@ async def export_cursor_fence(pool: asyncpg.Pool) -> AsyncIterator[None]:
86101
if unlocked is not True:
87102
conn.terminate()
88103
raise RuntimeError("export cursor advisory fence was not held")
104+
105+
106+
async def capture_cdc_snapshot_cutoff(pool: asyncpg.Pool) -> datetime:
107+
"""Return a commit-safe upper bound for one posting export tick.
108+
109+
The matching database trigger holds a shared transaction advisory lock
110+
from the first relevant statement until commit or rollback. Non-blocking
111+
exclusive probes avoid queuing healthy writers behind one long transaction.
112+
Once a probe succeeds:
113+
114+
* writers that stamped before this call must commit before it returns;
115+
* writers that reach the trigger while it is held stamp only after the
116+
returned cutoff; and
117+
* the exporter can safely query ``updated_at < cutoff`` without holding
118+
the lock during downstream network I/O.
119+
120+
A finite polling window bounds exporter staleness if a writer is wedged,
121+
without advancing a cursor or imposing that wait on new writers. Any
122+
acquisition/cutoff/release uncertainty terminates the dedicated pooled
123+
session so PostgreSQL releases a possibly-held lock.
124+
"""
125+
126+
async with pool.acquire() as conn:
127+
acquired = False
128+
started = time.monotonic()
129+
try:
130+
while not acquired:
131+
try:
132+
attempt = await conn.fetchval(_CDC_TRY_LOCK_SQL, CDC_WRITER_BARRIER_ID)
133+
except BaseException:
134+
conn.terminate()
135+
raise
136+
137+
if attempt is True:
138+
acquired = True
139+
break
140+
if attempt is not False:
141+
conn.terminate()
142+
raise RuntimeError("PostgreSQL returned an invalid CDC barrier result")
143+
144+
elapsed = time.monotonic() - started
145+
if elapsed >= _CDC_LOCK_TIMEOUT_SECONDS:
146+
exporter_cdc_barrier_timeouts.inc()
147+
log.error(
148+
"cdc_snapshot_barrier.timeout",
149+
timeout_s=_CDC_LOCK_TIMEOUT_SECONDS,
150+
)
151+
raise TimeoutError("timed out waiting for a commit-safe CDC cutoff")
152+
await asyncio.sleep(
153+
min(_CDC_LOCK_RETRY_SECONDS, _CDC_LOCK_TIMEOUT_SECONDS - elapsed)
154+
)
155+
156+
wait_s = time.monotonic() - started
157+
exporter_cdc_barrier_wait.observe(wait_s)
158+
if wait_s >= _CDC_SLOW_WAIT_SECONDS:
159+
log.warning(
160+
"cdc_snapshot_barrier.acquired_after_wait",
161+
wait_s=round(wait_s, 3),
162+
)
163+
164+
cutoff = await conn.fetchval(_CDC_CUTOFF_SQL)
165+
if not isinstance(cutoff, datetime):
166+
conn.terminate()
167+
raise RuntimeError("PostgreSQL returned an invalid CDC cutoff")
168+
return cutoff
169+
except BaseException:
170+
if acquired:
171+
conn.terminate()
172+
raise
173+
finally:
174+
if acquired and not conn.is_closed():
175+
try:
176+
unlocked = await conn.fetchval(_UNLOCK_SQL, CDC_WRITER_BARRIER_ID)
177+
except BaseException:
178+
conn.terminate()
179+
raise
180+
if unlocked is not True:
181+
conn.terminate()
182+
raise RuntimeError("CDC writer advisory barrier was not held")

apps/crawler/src/exporter.py

Lines changed: 30 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -14,7 +14,12 @@
1414
from prometheus_client import Counter, Gauge
1515

1616
from src.config import settings
17-
from src.export_cursor_fence import CursorFenceFactory, export_cursor_fence
17+
from src.export_cursor_fence import (
18+
CursorFenceFactory,
19+
CutoffFactory,
20+
capture_cdc_snapshot_cutoff,
21+
export_cursor_fence,
22+
)
1823
from src.metrics import (
1924
export_errors_total,
2025
exporter_export_lag,
@@ -24,6 +29,7 @@
2429
local_db_pool_idle,
2530
local_db_pool_size,
2631
r2_pending_gauge,
32+
reconciliation_discrepancies,
2733
redis_queue_depth,
2834
supa_db_pool_idle,
2935
supa_db_pool_size,
@@ -73,6 +79,7 @@
7379
# ---------------------------------------------------------------------------
7480

7581
_EPOCH = datetime.min.replace(tzinfo=UTC)
82+
_MAX_CDC_CUTOFF = datetime.max.replace(tzinfo=UTC)
7683
_ZERO_UUID = uuid.UUID(int=0)
7784

7885
# Sentinel stamped on Typesense `experience_max` for rows the extractor
@@ -995,6 +1002,8 @@ async def _export_postings_dual(
9951002
maps: TaxonomyMaps,
9961003
supa_backoff: _DownstreamBackoff | None = None,
9971004
ts_backoff: _DownstreamBackoff | None = None,
1005+
*,
1006+
cutoff: datetime = _MAX_CDC_CUTOFF,
9981007
) -> tuple[int, Cursor, Cursor]:
9991008
"""Fetch changed postings and upsert to both Supabase and Typesense concurrently.
10001009
@@ -1027,6 +1036,7 @@ async def _export_postings_dual(
10271036
fetch_ts,
10281037
fetch_id,
10291038
settings.export_batch_limit,
1039+
cutoff,
10301040
)
10311041
if not rows:
10321042
return 0, supa_cursor, ts_cursor
@@ -1256,7 +1266,8 @@ def select_changed_sql(cls, *extras: str) -> str:
12561266
+ cls.select_list(*extras)
12571267
+ " FROM "
12581268
+ cls.table
1259-
+ " WHERE (updated_at, id) > ($1, $2) ORDER BY updated_at, id LIMIT $3"
1269+
+ " WHERE (updated_at, id) > ($1, $2)"
1270+
+ " AND updated_at < $4 ORDER BY updated_at, id LIMIT $3"
12601271
)
12611272

12621273

@@ -1269,6 +1280,8 @@ async def _export_changed_postings(
12691280
local_pool: asyncpg.Pool,
12701281
supa_pool: asyncpg.Pool,
12711282
cursor: Cursor,
1283+
*,
1284+
cutoff: datetime = _MAX_CDC_CUTOFF,
12721285
) -> tuple[int, Cursor]:
12731286
"""Export job_posting rows changed since cursor to Supabase.
12741287
@@ -1286,6 +1299,7 @@ async def _export_changed_postings(
12861299
last_ts,
12871300
last_id,
12881301
settings.export_batch_limit,
1302+
cutoff,
12891303
)
12901304
if not rows:
12911305
return 0, cursor
@@ -1442,6 +1456,7 @@ async def run_exporter(
14421456
shutdown_event: asyncio.Event,
14431457
*,
14441458
cursor_fence_factory: CursorFenceFactory = export_cursor_fence,
1459+
cutoff_factory: CutoffFactory = capture_cdc_snapshot_cutoff,
14451460
) -> None:
14461461
"""Main exporter loop.
14471462
@@ -1486,6 +1501,12 @@ async def run_exporter(
14861501
if maps.stale:
14871502
await maps.refresh(local_pool, supa_pool)
14881503

1504+
# Probe until transactions that changed exported posting
1505+
# fields have committed, capture a clock cutoff, then
1506+
# immediately release the writer barrier. Rows stamped by
1507+
# later transactions stay above this strict upper bound.
1508+
cutoff = await cutoff_factory(local_pool)
1509+
14891510
# Two-cursor dual export
14901511
exported, posting_cursor, ts_cursor = await _export_postings_dual(
14911512
local_pool,
@@ -1495,6 +1516,7 @@ async def run_exporter(
14951516
maps,
14961517
supa_backoff,
14971518
ts_backoff,
1519+
cutoff=cutoff,
14981520
)
14991521
# Save both cursors in a single transaction so a crash
15001522
# between writes cannot leave one cursor advanced while
@@ -1513,8 +1535,12 @@ async def run_exporter(
15131535
exported = 0
15141536
else:
15151537
try:
1538+
cutoff = await cutoff_factory(local_pool)
15161539
exported, posting_cursor = await _export_changed_postings(
1517-
local_pool, supa_pool, posting_cursor
1540+
local_pool,
1541+
supa_pool,
1542+
posting_cursor,
1543+
cutoff=cutoff,
15181544
)
15191545
except Exception as exc:
15201546
if not _is_downstream_unavailable(exc):
@@ -1727,6 +1753,7 @@ async def run_reconciliation(
17271753
ts_discrepancies = await _reconcile_typesense(local_pool)
17281754
discrepancies += ts_discrepancies
17291755

1756+
reconciliation_discrepancies.inc(discrepancies)
17301757
log.info("reconciliation.completed", discrepancies=discrepancies)
17311758
return discrepancies
17321759

0 commit comments

Comments
 (0)