Skip to content

Fix flaky extract-pipeline E2E: warm cold-start ingest at the root#1857

Closed
JSv4 wants to merge 8 commits into
mainfrom
fix/e2e-extract-cold-start-ingest
Closed

Fix flaky extract-pipeline E2E: warm cold-start ingest at the root#1857
JSv4 wants to merge 8 commits into
mainfrom
fix/e2e-extract-cold-start-ingest

Conversation

@JSv4

@JSv4 JSv4 commented May 31, 2026

Copy link
Copy Markdown
Collaborator

Summary

The Extract pipeline (PDF upload → run → CSV) check (.github/workflows/frontend-e2e-extract.yml) red-X'd intermittently across multiple branches (#1825 / #1835 / #1836). This fixes the root cause in main so every PR benefits. Replaces the symptom-deferral in #1846 (issue #1844).

Root cause

The failing run did not fail an assertion — Playwright reported the test as flaky-passed ("1 flaky", exit 0). The red ✗ is a job cancellation: the first document ingest stalled past the 14-minute per-document wait, and that attempt (~18 min) plus the Playwright retry (~3.6 min) exceeded the job's timeout-minutes: 30, so GitHub cancelled the job mid-cleanup.

The stall is a cold start, not gradual slowness:

  • Docling loads its layout/table/OCR models lazily on the first /parse/ call. On a cold 2-core runner already hosting the docling (14 GB) + multimodal-embedder (7 GB) + privacy-filter (6 GB) images, that first parse balloons into a multi-minute, highly variable hang. The warm retry does the entire flow — 2 uploads, both ingests, extract, CSV — in 3.6 min.
  • The vector embedder is ready in ~4 s (verified), so it is not the bottleneck — which is why a health gate alone wouldn't have fixed it.
  • The worker runs --concurrency=1, so the two PDFs (incl. the large US Code fixture) parse + embed serially; the second doc (Eton) is what times out, queued behind the first.
  • The prior fix test(e2e): fix flaky Extract pipeline E2E document-processing timeout (#1844) #1846 only raised the wait 8 → 14 min, which deferred the symptom into the 30-min job timeout rather than removing it ("thought it was fixed but clearly not").

Changes

  • Warm-up step (frontend-e2e-extract.yml) — runs one real Docling parse of the small committed usc-title-1.pdf fixture + an embedder call before the timed spec, so both ingests run warm. Best-effort: warm-up failures warn but don't fail the job.
  • Readiness gating (local.yml) — /health healthchecks on vector-embedder, multimodal-embedder, docling-parser; django + celeryworker now gate on vector-embedder / docling-parser being service_healthy (was service_started). Benefits every environment, not just CI.
  • CELERY_WORKER_CONCURRENCY (compose/local/django/celery/worker/start) — worker honors this env var (default 1, unchanged for local dev); the extract workflow sets it to 2 so the two PDFs parse + embed concurrently.

Verification

  • docker compose -f local.yml config validates.
  • Healthcheck commands run against the real images: python urllib /health → 200 for all three; vector-embedder + docling-parser both flip to healthy.
  • Warm-up building blocks verified against real images (cold Docling parse succeeds; embedder /embeddings/batch → 200).
  • Warm-up heredoc passes bash -n and py_compile; pre-commit clean.
  • The real proof is this PR's own Extract pipeline run — it touches the workflow + helpers paths, so the check runs here.

Closes #1844

The `Extract pipeline (PDF upload → run → CSV)` check red-X'd
intermittently across PRs (#1825/#1835/#1836). It failed not on an
assertion but on a JOB CANCELLATION: the first document ingest stalled
past the 14-minute per-document wait, and that attempt (~18 min) plus
the Playwright retry (~3.6 min) blew the job's 30-minute
`timeout-minutes`. Playwright itself reported the run as flaky-passed.

Root cause is a cold start, not gradual slowness: Docling loads its
layout/table/OCR models lazily on the first `/parse/` call, and on a
cold 2-core runner already hosting the docling + multimodal +
privacy-filter images that first parse balloons into a multi-minute,
highly variable hang (the warm retry does the entire flow in 3.6 min).
The vector embedder, by contrast, is ready in seconds. The prior fix
(#1846) only raised the wait 8->14 min, deferring the symptom into the
job timeout rather than removing it.

Three changes attack the cause:

- Warm-up step (frontend-e2e-extract.yml): run one real Docling parse of
  the small committed usc-title-1.pdf fixture plus an embedder call
  before the timed spec, so both ingests run warm. Best-effort — warm-up
  failures warn but do not fail the job.
- Readiness gating (local.yml): add /health healthchecks to
  vector-embedder, multimodal-embedder, and docling-parser, and gate
  django + celeryworker on vector-embedder / docling-parser being
  service_healthy (was service_started, so the worker could start
  parsing before the services were listening).
- CELERY_WORKER_CONCURRENCY (worker start script): honor this env var
  (default 1, unchanged for local dev); the extract workflow sets it to
  2 so the two uploaded PDFs parse + embed concurrently instead of
  serialising behind a single child.

Healthcheck commands verified against the real images (python urllib
/health -> 200; both flip to healthy). compose config validates; the
warm-up heredoc passes bash -n and py_compile.
@claude

claude Bot commented May 31, 2026

Copy link
Copy Markdown

Code Review

Overview

This PR addresses a well-diagnosed root cause: Docling's lazy model loading on first /parse/ call causing intermittent job-cancellation timeouts in CI. The three-pronged fix (warm-up step, healthcheck gating, configurable concurrency) is targeted and well-reasoned. The root cause analysis in the PR description is thorough and accurate.


Issues

Bug: Warm-up step missing continue-on-error: true

The PR description and the inline comment both state the warm-up is best-effort — a failure should warn but not fail the job. The Python script honors this (all network calls are in try/except that print warnings and continue, so the script always exits 0). However, if the shell-level docker compose exec command itself fails (e.g., the django container is not yet running, the exec times out, or Docker is unhealthy), the step fails and blocks the job — which is the opposite of the stated intent.

# As-written: a docker-level failure blocks the job
- name: Warm up Docling parser + embedder (load models off the test clock)
  run: |
    docker compose -f local.yml exec -T django python - <<'PY'
    ...
    PY

# Should be:
- name: Warm up Docling parser + embedder (load models off the test clock)
  continue-on-error: true
  run: |
    docker compose -f local.yml exec -T django python - <<'PY'
    ...
    PY

This is the only functional bug I see.


Observations / Minor Notes

Hardcoded abc123 API key in workflow

headers={"Content-Type": "application/json", "X-API-Key": "abc123"},

abc123 is documented as a local-dev placeholder (it's in local.yml too), so this is fine for CI. Just worth noting that if the local dev key ever changes in local.yml, the workflow would need a parallel update. A future improvement could reference an env var set in the job, but it's not a problem as-is.

Inconsistency between celeryworker deps and new healthchecks

multimodal-embedder receives a healthcheck (good) but neither django nor celeryworker gates on service_healthy for it — both still use service_started. This is an intentional choice (the bottleneck is Docling, not the multimodal embedder), and the comment in local.yml acknowledges this. The asymmetry (healthcheck defined but not used as a startup gate) could be confusing to a future reader. Consider either: (a) adding a brief comment on the multimodal-embedder entry noting it's not a startup blocker, or (b) gating celeryworker on it too (low cost since it defines the healthcheck anyway). Not a blocker.

wait_health inside the warm-up script is redundant with Docker healthchecks

The warm-up Python script calls wait_health() for vector-embedder and docling-parser before sending the parse request. By the time this step runs, Docker's depends_on: condition: service_healthy should have already ensured those services are healthy (the django container itself gates on them). The extra poll is harmless and a useful safety net (e.g., if a flapping restart occurs), but it slightly extends the step if health is slow. Not a bug.

retries values differ without explanation

docling-parser and multimodal-embedder use retries: 12, vector-embedder uses retries: 10. The difference is small (100s vs 120s of health poll budget after start_period), but an inline comment noting the reason (e.g., "Docling image is larger / loads slower") would help future readers calibrate if they need to adjust.


What's Good

  • Root cause is correctly identified and well-documented — the PR description is exemplary.
  • The warm-up is off the test clock, which is the right design: the spec's timer isn't polluted.
  • CELERY_WORKER_CONCURRENCY defaulting to 1 (unchanged for local dev) is correct; only CI overrides it.
  • The healthcheck commands using python -c "urllib.request..." avoid shell-level dependency on curl/wget which may not be in every image.
  • CHANGELOG entry is detailed and references issue/PR numbers.
  • Best-effort failures are surfaced as WARNING: to stderr, which CI logs will capture without blocking.

Summary

One real issue: add continue-on-error: true to the warm-up step to honor the best-effort promise end-to-end. Everything else is minor. The core approach is sound and the implementation is clean.

First fix attempt (warm-up of docling/embedder microservices) did NOT
resolve the stall: CI showed `docling warmup parse: 200 in 31.3s` (models
warm) yet attempt 1 still took 15 min and the job was cancelled at the
30-min cap. So the docling microservice cold-load is NOT the bottleneck.
The thing the warm-up did not touch is the celeryworker's own first-task
processing (the warm-up hit docling/embedder from the django container,
not through the worker), and the prime remaining suspect is host memory
thrash (concurrency=2 worker children + the 7 GB multimodal-embedder the
extract test never uses, on a 2-core/7 GB runner).

We were debugging blind: on cancellation the `failure()` log-capture
steps were skipped, so no worker logs were ever uploaded.

This commit is observability only (no fix):
- Capture step -> `if: always()` (runs on cancellation) and now also
  dumps celeryworker.log + django.log (timestamped), `docker stats`,
  `free -h`/meminfo, and dmesg OOM hits.
- Disable Playwright retry (`--retries=0`) for this diagnostic pass so a
  cold stall fails in-budget, Playwright prints which step/doc failed,
  and the capture uploads cleanly instead of racing the job cancel.

Revert the diagnostic retry change once the root cause is confirmed.
@claude

claude Bot commented May 31, 2026

Copy link
Copy Markdown

test comment

@claude

claude Bot commented May 31, 2026

Copy link
Copy Markdown

Code Review

Summary: Well-diagnosed fix for a subtle cold-start flakiness issue. The three-pronged approach (warm-up, healthcheck gating, concurrency) addresses the root cause correctly. A few things worth addressing before merge.


Issues

1. Warm-up step is not actually best-effort at the shell level

The PR description says "warm-up failures warn but don't fail the job", and the Python script handles failures gracefully via try/except. However, if docker compose exec -T itself exits non-zero (e.g., the django container crashed before this step), the entire workflow step fails and blocks the job — the Python exception handling never gets a chance to run.

Add continue-on-error: true to the step:

- name: Warm up Docling parser + embedder (load models off the test clock)
  continue-on-error: true   # add this
  run: |
    docker compose -f local.yml exec -T django python - <<'PY'
    ...

Without it, a docker-level failure breaks the job before the spec runs — the opposite of the stated intent.


2. multimodal-embedder healthcheck is defined but not used as a gate

multimodal-embedder gets a healthcheck in this PR, but django still depends on it with service_started (not service_healthy), and it is not added to celeryworker dependencies at all. If it was excluded deliberately (not on the critical ingest path for this test), a one-line comment saying so would prevent future confusion. Otherwise, changing it to service_healthy for consistency would be the right fix.


Observations

3. --retries=0 is documented as temporary — should it be restored here?

The inline comment says "Restore retries once the root cause is fixed." This PR claims to fix the root cause. Is the intent to restore retries in a follow-up, or should they be restored now? Either way, tracking this with an open issue or a TODO with a number would prevent it from becoming stale technical debt.

4. wait_health budget in the warm-up script could be shorter

By the time the warm-up step runs, depends_on: condition: service_healthy has already verified the services are reachable. The 180s polling budget in wait_health covers something that should already be satisfied. Shortening to ~30s would save time on the happy path without meaningfully increasing risk.

5. Concurrency=2 on an already-loaded 2-core runner

Raising CELERY_WORKER_CONCURRENCY to 2 on a runner already hosting docling (14 GB) + multimodal-embedder (7 GB) + privacy-filter (6 GB) images could cause memory pressure or CPU thrash. The enhanced docker stats artifact added here will surface this if it happens — worth watching the first few runs.


Positives

  • Root cause diagnosis is precise: distinguishing "lazy model load on first parse call" from "service not started" is non-obvious and well-documented in the comments.
  • Best-effort design philosophy is correct: the try/except pattern in Python is right — it just needs continue-on-error: true at the shell level to fully deliver on that promise.
  • if: always() instead of failure() is the right call for cancelled-job artifact capture. The comment explaining why (cancelled jobs skip failure() steps) is exactly the kind of non-obvious "why" that belongs in a comment.
  • Default concurrency stays at 1 for local dev — fully backward-compatible.
  • CHANGELOG entry is detailed enough to be useful retroactively.

The main blocker before merge is the missing continue-on-error: true on the warm-up step (issue 1). The healthcheck inconsistency (issue 2) is also worth addressing to avoid leaving an incomplete fix. The rest are low-priority observations.

JSv4 added 2 commits May 31, 2026 11:30
…e, shorten health budget, track retries

- Add continue-on-error: true to the warm-up step so a docker-level failure
  (container crashed before the step) can't block the job — the warm-up is an
  optimisation, never a gate (review #1, the main blocker).
- Document why multimodal-embedder is gated service_started (not
  service_healthy) and is not a direct celeryworker dependency: it serves
  image embeddings, off the text/PDF ingest path this pipeline exercises, and
  gating on its health would add ~7GB-image boot latency to every local up
  (review #2).
- Shorten the warm-up wait_health budget 180s -> 30s now that depends_on
  gates the services healthy before the step runs (review #4).
- Turn the --retries=0 note into a tracked TODO(#1844 follow-up) so the
  diagnostic setting doesn't silently become permanent (review #3).
@claude

claude Bot commented May 31, 2026

Copy link
Copy Markdown

Code Review

Overview

This PR addresses the root cause of the flaky Extract pipeline (PDF upload → run → CSV) E2E check, which was job cancellation due to Docling's lazy model loading on a cold 2-core CI runner. The three-pronged fix (warm-up + healthchecks + concurrent worker) is well-motivated and the root-cause analysis is thorough.


Positives

  • Accurate diagnosis. The distinction between a Playwright flaky-passed vs. a GitHub job cancellation is subtle. The analysis is correct and well-documented.
  • Best-effort warm-up. continue-on-error: true is the right call — the warm-up is an optimisation, never a gate.
  • Healthchecks are additive. Adding /health gates to vector-embedder, docling-parser, and multimodal-embedder in local.yml benefits all environments, not just CI.
  • if: always() for log capture is the correct fix for the observability gap — cancelled jobs skip failure() steps, which is why prior runs captured nothing.
  • Changelog entry is detailed and references upstream issues.

Issues / Concerns

1. --retries=0 is a diagnostic setting with no enforcement mechanism

The TODO comment acknowledges this needs to be reverted once the fix proves stable, but there is nothing to ensure that happens. A transient network blip will now unconditionally red-X the job instead of being absorbed by a retry. Recommend either opening a follow-up issue (the TODO references #1844 follow-up), or restoring the default retry count now if the warm-up makes the test reliably deterministic.

2. Warm-up timeout of 600s is long relative to the 30-minute job budget

r = urllib.request.urlopen(req, timeout=600)

If Docling hangs during the warm-up (e.g. OOM on a cold runner), this step blocks for up to 10 minutes before continue-on-error: true kicks in — a third of the total job budget gone before the actual test starts. The warm-run description shows the whole flow completes in 3.6 min, so a hung warm-up past ~5 min is almost certainly an OOM, not slow loading. Consider capping at 300s or 180s.

3. Unrelated binary file in the diff

docs/assets/images/screenshots/auto/maps--annotation-map--pin-panel.png

This screenshot appears unrelated to the CI fix. Project conventions commit auto-screenshots via the screenshots.yml workflow, not in feature PRs. Worth removing unless intentional.

4. if: always() on artifact upload increases storage on every green run

- name: Upload backend logs + stats
  if: always()
  uses: actions/upload-artifact@v7

Consider if: failure() || cancelled() instead — this covers the cancellation case (the gap this PR is solving) while avoiding artifact accumulation on green runs. cancelled() is a valid GitHub Actions expression.

5. File handle not closed in warm-up script

"pdf_base64": base64.b64encode(open(pdf, "rb").read()).decode(),

Minor: open() without with leaves the handle unclosed until GC. Suggest with open(pdf, "rb") as f: data = f.read(). Not a functional issue in this short-lived process, but worth keeping clean.

6. Hardcoded concurrency value tied to current test structure

echo "CELERY_WORKER_CONCURRENCY=2" >> .envs/.local/.django

The value 2 is chosen because the test uploads exactly 2 PDFs. If the test grows, this needs updating. A brief comment linking the value to the document count would make the relationship explicit and prevent silent staleness.


Minor Nits

  • The wait_health budget of 30s in the warm-up is reasonable since service_healthy has already verified these services before this step runs. A short inline comment explaining that assumption would help future readers.
  • healthcheck.retries: 12 on docling-parser (12 x 10s = 120s) plus start_period: 40s means up to 160s before Docker marks it unhealthy. Correct for a 14 GB image, but local devs will see longer docker compose up times. The existing comment about multimodal boot latency is a good precedent — a similar note for Docling would help.

Summary

The root-cause analysis is solid and the three-part fix is the right approach. Main actionable items:

  1. Track or revert --retries=0 before it quietly becomes permanent.
  2. Cap the warm-up timeout (~300s) to protect the job budget if Docling hangs during warm-up.
  3. Remove the unrelated screenshot file from this PR.
  4. Consider if: failure() || cancelled() for artifact upload to avoid storage churn on green runs.

JSv4 added 2 commits May 31, 2026 16:21
The maps--annotation-map--pin-panel.png auto-screenshot belongs to the
AnnotationMap feature (#1820), not this CI fix. Auto-screenshots are
committed via the screenshots.yml workflow, not in feature PRs.
JSv4 added 2 commits May 31, 2026 21:03
…re/cancel, tidy file handle + concurrency note

- Cap the Docling warm-up parse at 300s (was 600s): a warm-up hang past
  ~5 min is almost certainly an OOM on the cold runner, so fail fast
  instead of burning a third of the 30-min job budget before the spec.
- Capture + upload backend logs on 'failure() || cancelled()' instead of
  'always()': still covers the timeout-cancellation gap this PR targets
  while avoiding artifact churn on green runs.
- Read the warm-up PDF via 'with open(...)' so the handle is closed.
- Note that CELERY_WORKER_CONCURRENCY=2 is tied to the spec's two PDF
  fixtures so the relationship doesn't go stale.
@claude

claude Bot commented Jun 1, 2026

Copy link
Copy Markdown

Code Review

Overview

This PR fixes a genuinely tricky intermittent CI failure by addressing the root cause (lazy Docling model loading on first parse call) rather than just bumping a timeout again. The root-cause analysis in the PR description is thorough and persuasive — the "warm retry did the whole 2-upload flow in 3.6 min" observation is compelling evidence that cold-start is the real culprit.

The three-part fix (warm-up step + readiness gating + concurrency unlock) is well-layered. Changes are non-breaking for local dev.


Strengths

Root-cause fix, not symptom deferral. #1846 raised the timeout 8 to 14 min and pushed the stall into the job-level cancellation. This PR removes the stall from the hot path entirely.

failure() || cancelled() log capture is the most underrated change here. The prior failure() condition silently skipped log upload on the cancellation that was actually happening — fixing this alone gives much better future diagnostics.

Best-effort warm-up (continue-on-error: true) is the right call. If the warm-up itself OOMs or times out, the spec still runs and surfaces the regression rather than silently hiding it behind a pre-gate failure.

Healthchecks benefit local dev too, not just CI. Cleaner startup ordering is a general improvement.


Concerns

1. --retries=0 is the right diagnostic move but needs a hard follow-up gate.

The TODO comment (TODO(#1844 follow-up): keep --retries=0 only until) is clear, but TODO comments in workflow files have a history of quietly becoming permanent. Consider opening a follow-up issue (or confirming #1844 tracks this explicitly) and referencing the issue number rather than just the follow-up label. A transient Docker network hiccup in CI would permanently fail the job with --retries=0 in place.

2. Warm-up parse timeout (300 s) eats job budget on OOM.

The comment correctly notes that a 5-min hanging warm-up is "almost certainly an OOM." But with continue-on-error: true, a 300 s warm-up stall + the main spec run could together leave very little headroom in the 30-min job budget. Consider whether 180 s (3 min) is a more conservative ceiling given the 3.6-min warm-run reference point.

3. multimodal-embedder gets a healthcheck but is not used as a gate — minor inconsistency.

Adding the healthcheck is fine for observability and future use, and the comment explains why it is deliberately service_started. One small nit: the comment lives in the django depends_on block but the healthcheck is defined on the service itself ~30 lines later. A short note on the service definition ("healthcheck defined but not a startup gate — see depends_on comment") would save a reader from wondering why the healthcheck exists but is never depended on.

4. Healthcheck retries are generous — may slow down failure detection in local dev.

docling-parser and multimodal-embedder both use retries: 12 / start_period: 40s with interval: 10s. In the worst case a failing service is only declared unhealthy after 40 + 120 = 160 s. Fine for CI, but could mask a broken image during local development for nearly 3 minutes. retries: 6 (60 s after start_period) would still be generous and halve the detection window.

5. Hardcoded X-API-Key: abc123 in the warm-up script.

This is already in local.yml, so this PR does not introduce new exposure. But since the key appears in plaintext in the workflow file, it is worth confirming CI does not proxy to any non-local service with this key. The existing local.yml comment ("local-only placeholder; override before deploying") covers it, but restating that in the workflow comment would close the loop.


Minor / Nits

  • The CHANGELOG entry is detailed and useful, but the single-bullet format with a ~300-word sentence will be hard to scan in a rendered changelog. The PR description already reads like good changelog prose — consider splitting into sub-bullets (root cause / warm-up / healthchecks / concurrency) mirroring the "Changes" section above.

  • wait_health inside the warm-up heredoc re-polls with a 30 s budget even though service_healthy already waited. This is explicitly noted as covering "a brief readiness gap" — fine, just confirming this is intentional.

  • The celeryworker depends_on in local.yml adds vector-embedder: service_healthy but omits multimodal-embedder for the same boot-latency reason as the django block. Worth a brief comment on the celeryworker section (mirroring the one on django) so future readers do not add it thinking it was an oversight.


Summary

Solid, well-analysed fix. The mechanics are correct, the documentation is unusually thorough, and the changes are scoped appropriately. The main ask is making sure --retries=0 does not quietly persist — everything else is polish.

@JSv4 JSv4 closed this Jun 4, 2026
@JSv4 JSv4 deleted the fix/e2e-extract-cold-start-ingest branch June 4, 2026 05:21
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.

Flaky CI: "Extract pipeline (PDF upload → run → CSV)" E2E times out on document processing

1 participant