Query 500 after 120 s: synchronous embed backfill in the request path has no time budget #1

New issue

Open

opened 2026-10-09 03:14:56 +02:00 by damienmoon · 0 comments

damienmoon commented

2026-10-09 03:14:56 +02:00

Owner

Observed

Fresh install (ctx.damienmoon.sh, build 38fdb74f, v5.21.1). First ctx query after saving a ~33 kB block (≈10k tokens) fails with HTTP 500 after exactly 120 s. The synthesis backend (Haiku via ctx-shim) is not involved — the translation step completed in 1.4 s.

Server log (request c271f3b0203621c2):

01:00:55 query pipeline start
01:00:56 query translated  (shim: POST /v1/chat/completions 200 1452ms)
01:02:55 WARN  query backfill: embed failed — memoized  block_id=01a11e26-562c-… class=wire
                error: Post "http://ctx-embed:8081/v1/embeddings": context canceled
01:02:55 INFO  query: backfilled embeddings before search count=1
01:02:55 ERROR embedding failed  error="embedcache: admission: context canceled"
01:02:55 http request POST /api/query status=500 duration_ms=119997

ctx-embed (Qwen3-Embedding-8B-Q8_0, CPU, --threads 16, recommended f16/kv-unified config from docs/operations.md) processes at ~28 tok/s:

prompt processing, n_tokens = 3072, progress = 0.30, t = 110.30 s / 27.85 tokens per second
srv stop: cancel task, id_task = 2

A 10k-token block therefore needs ~6 min to embed; the request deadline is 120 s.

Why this is more than a tuning problem

QueryHandler.backfillPending (go/internal/handler/query.go:1710, called at :832) runs the pending-embedding backfill synchronously inside the request, bounded only by embed_backfill.sync_cap (count of blocks, default 4) — not by time. Consequences on a slow embed backend:

One pending block whose embed cannot finish within the request deadline consumes the entire deadline. The question's own embedding is then never admitted (embedcache: admission: context canceled), so the query fails with 500 instead of degrading to search-without-that-block.
Each such query burns ~120 s of embed CPU for nothing (the llama.cpp task is cancelled at 30 %), and the failure is memoized with the wire class → finite backoff (60 s · 2ⁿ, cap 24 h). Until the scheduler arm (backfillOneEmbedding) succeeds in the background, every query that lands while the memo has expired repeats the 120 s failure.
The failure class is wrong for this case: wire is meant to signal "backend down". Here the backend is healthy, just slow relative to the caller's deadline — a caller-timeout class with "leave it to the background arm" semantics would avoid the repeated 120 s burns.

The code comment acknowledges the shape ("the known lopsidedness (an unbounded backfill loop ahead of the search) is NOT solved here, only honestly classified").

Suggested direction

Give the sync backfill a time budget (fraction of the request deadline, e.g. 20–30 %) in addition to sync_cap, and reserve the remainder for the question embed + search. A block that does not fit the budget is left to the scheduler arm, not attempted.
On sync-backfill timeout: do not memoize as wire; either skip without a memo or use a dedicated class with a short fixed backoff so the background arm picks it up at once.
Query must degrade (search without the pending block, FTS still finds it) rather than 500.

Side note

query.go:732 logs german detected, translating for a Swedish question. Harmless (translation to English is correct), but the detector label is misleading.

Deployment side (separate, not a ctx bug)

--threads 16 on a 48-core host; raising it is the cheap local fix. Long-term the docs already say embeddings belong on a GPU.

## Observed Fresh install (ctx.damienmoon.sh, build `38fdb74f`, v5.21.1). First `ctx query` after saving a ~33 kB block (≈10k tokens) fails with HTTP 500 after exactly 120 s. The synthesis backend (Haiku via ctx-shim) is not involved — the translation step completed in 1.4 s. Server log (request `c271f3b0203621c2`): ``` 01:00:55 query pipeline start 01:00:56 query translated (shim: POST /v1/chat/completions 200 1452ms) 01:02:55 WARN query backfill: embed failed — memoized block_id=01a11e26-562c-… class=wire error: Post "http://ctx-embed:8081/v1/embeddings": context canceled 01:02:55 INFO query: backfilled embeddings before search count=1 01:02:55 ERROR embedding failed error="embedcache: admission: context canceled" 01:02:55 http request POST /api/query status=500 duration_ms=119997 ``` ctx-embed (Qwen3-Embedding-8B-Q8_0, CPU, `--threads 16`, recommended f16/kv-unified config from docs/operations.md) processes at ~28 tok/s: ``` prompt processing, n_tokens = 3072, progress = 0.30, t = 110.30 s / 27.85 tokens per second srv stop: cancel task, id_task = 2 ``` A 10k-token block therefore needs ~6 min to embed; the request deadline is 120 s. ## Why this is more than a tuning problem `QueryHandler.backfillPending` (`go/internal/handler/query.go:1710`, called at `:832`) runs the pending-embedding backfill **synchronously inside the request**, bounded only by `embed_backfill.sync_cap` (count of blocks, default 4) — not by time. Consequences on a slow embed backend: 1. One pending block whose embed cannot finish within the request deadline consumes the **entire** deadline. The question's own embedding is then never admitted (`embedcache: admission: context canceled`), so the query fails with 500 instead of degrading to search-without-that-block. 2. Each such query burns ~120 s of embed CPU for nothing (the llama.cpp task is cancelled at 30 %), and the failure is memoized with the `wire` class → finite backoff (60 s · 2ⁿ, cap 24 h). Until the scheduler arm (`backfillOneEmbedding`) succeeds in the background, every query that lands while the memo has expired repeats the 120 s failure. 3. The failure class is wrong for this case: `wire` is meant to signal "backend down". Here the backend is healthy, just slow relative to the caller's deadline — a *caller-timeout* class with "leave it to the background arm" semantics would avoid the repeated 120 s burns. The code comment acknowledges the shape ("the known lopsidedness (an unbounded backfill loop ahead of the search) is NOT solved here, only honestly classified"). ## Suggested direction - Give the sync backfill a **time budget** (fraction of the request deadline, e.g. 20–30 %) in addition to `sync_cap`, and reserve the remainder for the question embed + search. A block that does not fit the budget is left to the scheduler arm, not attempted. - On sync-backfill timeout: **do not** memoize as `wire`; either skip without a memo or use a dedicated class with a short fixed backoff so the background arm picks it up at once. - Query must degrade (search without the pending block, FTS still finds it) rather than 500. ## Side note `query.go:732` logs `german detected, translating` for a Swedish question. Harmless (translation to English is correct), but the detector label is misleading. ## Deployment side (separate, not a ctx bug) `--threads 16` on a 48-core host; raising it is the cheap local fix. Long-term the docs already say embeddings belong on a GPU.

damienmoon referenced this issue from a commit

2026-10-09 03:40:36 +02:00

ops(ctx): dream on since 2026-10-09, JSON mode off for the shim

damienmoon referenced this issue from a commit

2026-10-09 04:14:29 +02:00

ops(ctx): pin a677b2d7, the fork commit with the fix for damienmoon/ctx#1

damienmoon referenced this issue from a commit

2026-10-09 04:29:23 +02:00

ops(ctx): dream on since 2026-10-09, JSON mode off for the shim

damienmoon referenced this issue from a commit

2026-10-09 04:29:42 +02:00

ops(ctx): pin a677b2d7, the fork commit with the fix for damienmoon/ctx#1