fix(onlion): bound the embedding path by the invocation, not the provider

docs/decisions/implemented/2026-10-29-embedding-invocation-budget.md

@@ -0,0 +1,130 @@
+# The embedding path is bounded by the invocation, not by the provider
+
+[简体中文](2026-10-29-embedding-invocation-budget.zh-CN.md) · [Terms](2026-10-29-embedding-invocation-budget.terms.yaml)
+
+**Status:** implemented
+**Approved:** explicit
+
+## Problem
+
+A scored run was killed twice. The platform log for 2026-10-29 holds **220 invocations
+that all ran exactly 120000 ms** - the EdgeOne ceiling, already configured as
+`cloudFunctions.maxDuration: 120` - with resident memory between 762 MB and 1014 MB
+(p50 892, p95 999). Every one of them was killed, not merely slow.
+
+The failure had two phases with different causes, and the account balance was not one of
+them:
+
+| window              | what happened                                                                                                                                   |
+| ------------------- | ----------------------------------------------------------------------------------------------------------------------------------------------- |
+| 05:18:45 - 10:43:36 | 220 invocations hung to the ceiling with credit available (34 in the 05 hour, 17 in 08, 129 in 09, 40 in 10)                                    |
+| 10:44:17 - 10:45:36 | 21 `embedding_http_400` events across 17 traces, all inside 52 seconds: the provider started rejecting requests, and those requests failed fast |
+
+Arrears explains the second window only. The first window is the one that consumed 7.3
+instance-hours of stalled invocations, and it happened while the provider was _slow_, not
+refusing.
+
+## Root cause
+
+`onlion` forced a per-attempt embedding timeout larger than it thought:
+
+```js
+// onlion/backend/worker.mjs
+NMG_EMBED_TIMEOUT_MS: env.NMG_EMBED_TIMEOUT_MS ?? "90000",
+```
+
+The provider client retries a timeout, on the theory that the request may simply have been
+slow:
+
+```js
+// src/core/openai-embedding.ts
+} catch (error) {
+  // A timeout is retried too: the request may simply have been slow.
+  if (attempt >= RETRY_DELAYS_MS.length) throw error;
+}
+```
+
+So one logical call costs `90 s + 0.15 s + 90 s` before it fails - already past the 120 s
+ceiling - and the pending-record fusion made up to **forty sequential calls** in a single
+search:
+
+```js
+for (const list of features) for (const text of list) await client.embedQueries([text]);
+for (const record of waiting) await client.embedQueries([record.content]);
+```
+
+Forty calls that each abort at 90 s within a 120 s invocation is not a slow request. It is
+a request that cannot finish, and the platform answers for us by killing it. A killed
+invocation leaves no diagnostics at all, which is why the incident looked like "every
+request took exactly 120 s" and nothing more.
+
+## Decision
+
+Bound the embedding path by the invocation:
+
+1. **Per-attempt timeout 10 s** (`EMBED_TIMEOUT_MS`), the provider client's own default,
+   instead of the forced 90 s.
+2. **A timeout is not retried.** A connection reset still is: it says nothing about the
+   endpoint being slow.
+3. **One batch call, not one call per text.** The vectors are identical; only the number of
+   round trips changes. The fusion now collects every feature text and every pending
+   record into a single request.
+4. **A 25 s total budget per request for query-side embedding** (`NMG_EMBED_QUERY_BUDGET_MS`),
+   shared by every call site. Past it, a call rejects, and every caller already degrades to
+   scoring by term overlap. Documents are excluded: they carry the memory itself, so the
+   per-attempt timeout and the batch size bound them instead.
+5. **A 20 s timeout on every COS request**, surfaced as a retryable error. Nothing bounded
+   these, so a stalled bucket produced the same 120 s death.
+6. **A 60 s slow-request report** (`nmg_slow_request`, with trace id, route, elapsed time
+   and queue state) because the 120 s kill leaves nothing behind.
+7. `/health limits` reports `embed_timeout_ms`, `embed_query_budget_ms` and `slow_report_ms`
+   so the numbers that bound an invocation are visible instead of inferred.
+
+## Evidence
+
+| claim                                    | how it is established                                                                                                    |
+| ---------------------------------------- | ------------------------------------------------------------------------------------------------------------------------ |
+| the platform ceiling is what killed them | 220 of 220 timeout rows report `运行时间 = 120000`; `maxDuration: 120` is already the platform maximum                   |
+| the timeouts were not the arrears window | the 21 provider rejections are all inside 10:44:17-10:45:36, after the last timeout at 10:43:36                          |
+| the path issued one call per text        | before the change, a search over six pending records produced **7 embedding calls with 1/1/1/1/1/1/1 inputs**            |
+| it now issues one call                   | after the change, the same search produces **1 call with 8 inputs**, and the test asserts it                             |
+| a timeout is not retried                 | `tests/core/openai-embedding.test.ts`: a server slower than the budget is contacted exactly once, past both retry delays |
+| resets still retry                       | same file: a socket destroyed on the first attempt is retried and the embedding succeeds on the second                   |
+
+## What this does and does not establish
+
+- **Memory pressure is not ruled out.** 220 invocations died between 762 MB and 1014 MB, and
+  if the instance limit is 1 GiB that is 88-99% occupancy. A killed invocation reports no
+  stage timings, so the data cannot separate "waiting on a slow provider" from "GC thrash at
+  the ceiling". The 60 s report is what will separate them next time.
+- **The provider's own behaviour is unverified.** A 400 was classified by status only. The
+  response body is already in the exception message, and `NMG_DEBUG_ERRORS=1` records it;
+  without that flag the log cannot distinguish "insufficient balance" from a malformed batch.
+- **The 90 s default was not chosen deliberately anywhere.** No record explains it; it is
+  treated here as a defect rather than a decision being reversed.
+
+## Alternatives considered
+
+- **Raise `maxDuration`.** Already at the platform maximum of 120 s.
+- **Blame the OPFS initialisation noise.** `sqliteReady()` memoises its instance, so the
+  VFS install happens once per isolate and its failure is swallowed by the SQLite module.
+  The repeated log lines are concurrent isolates, not retries, and they cost no measurable
+  time.
+- **Treat the provider rejections as the cause of the timeouts.** A non-retryable status is
+  returned immediately by the client, and those rejections arrive 41 seconds after the last
+  timeout.
+
+## Consequences
+
+- A slow provider now costs a degraded score, not a dead invocation: the search still
+  answers, from term overlap where a vector is missing.
+- Batch fusion is also cheaper for a healthy provider: one round trip instead of up to
+  forty, which is the same reduction in latency and in the provider's own load.
+- The write path keeps its generous behaviour. Documents are not budgeted, so a large Add
+  is not truncated by the query budget - it is bounded by the per-attempt timeout and the
+  batch size instead.
+- An operator can read the three bounding numbers from `/health limits`, and a request that
+  survives 60 s now says so in the log while it is still alive.
+- Not addressed: resident memory between 762 MB and 1014 MB per invocation. If the instance
+  limit is 1 GiB this is the next failure to look for, and the slow-request report is what
+  will show whether it is memory or waiting.

docs/decisions/implemented/2026-10-29-embedding-invocation-budget.terms.yaml

@@ -0,0 +1,3 @@
+version: 2
+terms: []
+references: []

docs/decisions/implemented/2026-10-29-embedding-invocation-budget.zh-CN.md

@@ -0,0 +1,100 @@
+# embed 路径由调用时长约束，而不是由上游决定
+
+[English](2026-10-29-embedding-invocation-budget.md) · [Terms](2026-10-29-embedding-invocation-budget.terms.yaml)
+
+**Status:** implemented
+**Approved:** explicit
+
+## 问题
+
+一次计分跑被中断了两次。平台日志里，2026-10-29 有 **220 次调用全部精确跑了 120000 ms**
+——那就是 EdgeOne 的上限（`cloudFunctions.maxDuration: 120` 已经配好）——常驻内存
+762 MB 到 1014 MB（p50 892，p95 999）。没有一条是"慢"，全是被杀。
+
+失败分两段，成因不同，**欠费只解释第二段**：
+
+| 时间窗              | 发生了什么                                                                                  |
+| ------------------- | ------------------------------------------------------------------------------------------- |
+| 05:18:45 – 10:43:36 | 220 次调用挂到上限，此时账户还有额度（05 点 34 次、08 点 17 次、09 点 129 次、10 点 40 次） |
+| 10:44:17 – 10:45:36 | 52 秒内 21 条 `embedding_http_400`，17 个 trace；上游开始拒绝，这些请求快速失败             |
+
+占掉 7.3 个实例·小时的是第一段，它发生在上游"慢"而不是"拒绝"的时候。
+
+## 根因
+
+`onlion` 强制的单次嵌入超时比它自己以为的更大：
+
+```js
+// onlion/backend/worker.mjs
+NMG_EMBED_TIMEOUT_MS: env.NMG_EMBED_TIMEOUT_MS ?? "90000",
+```
+
+而客户端会重试超时（注释原文是"请求可能只是慢"）：
+
+```js
+// src/core/openai-embedding.ts
+} catch (error) {
+  // A timeout is retried too: the request may simply have been slow.
+  if (attempt >= RETRY_DELAYS_MS.length) throw error;
+}
+```
+
+于是一次逻辑调用要花 `90 s + 0.15 s + 90 s` 才失败——已经越过 120 s 上限——而 pending 融合在
+单次检索里最多发起 **40 次串行调用**。40 次各以 90 s 超时兜底的调用落在 120 s 的调用预算里，
+不是"慢请求"，是**不可能完成的请求**，平台替我们杀掉了它。而被杀的调用不留下任何诊断，
+所以事故看起来只剩"每条都是 120 s"。
+
+## 决策
+
+用调用时长约束 embed 路径：
+
+1. **单次超时 10 s**（`EMBED_TIMEOUT_MS`），即客户端自己的默认值，取代强制的 90 s。
+2. **超时不重试**；连接重置仍然重试，因为它不说明上游慢。
+3. **一次批量调用，而不是每个文本一次**：向量完全相同，改变的只是往返次数。
+4. **query 侧嵌入每请求 25 s 总预算**（`NMG_EMBED_QUERY_BUDGET_MS`），所有调用点共享。用尽后
+   调用被拒绝，而每个调用方本来就已降级为词重叠打分。文档侧不设预算：它承载记忆本身，
+   由单次超时与批量大小约束。
+5. **COS 每次请求 20 s 超时**，并作为可重试错误上抛。此前没有任何东西约束它，卡住的桶同样
+   制造 120 s 死亡。
+6. **60 s 慢请求自报**（`nmg_slow_request`，带 trace、路由、耗时与队列状态），因为被杀的调用
+   什么都不留。
+7. `/health limits` 报出 `embed_timeout_ms`、`embed_query_budget_ms`、`slow_report_ms`，
+   让约束调用的数字可见，而不是靠推断。
+
+## 证据
+
+| 论断                     | 依据                                                                                |
+| ------------------------ | ----------------------------------------------------------------------------------- |
+| 是平台上限杀的           | 220 条全部 `运行时间 = 120000`，且 `maxDuration` 已是平台最大值                     |
+| 挂死不发生在欠费窗口     | 21 条上游拒绝全部落在 10:44:17–10:45:36，晚于最后一次超时 10:43:36                  |
+| 修复前是"每文本一次调用" | 六条 pending 记录的一次检索产生 **7 次调用，输入数 1/1/1/1/1/1/1**                  |
+| 修复后是一次             | 同一次检索产生 **1 次调用、8 个输入**，测试断言此性质                               |
+| 超时不重试               | `tests/core/openai-embedding.test.ts`：比预算更慢的服务只被访问一次，已越过两段退避 |
+| 重置仍重试               | 同文件：首次尝试被销毁的 socket 会重试，第二次成功                                  |
+
+## 这确立了什么、没有确立什么
+
+- **内存压力没有被排除。** 220 次调用死在 762–1014 MB 之间，若实例上限是 1 GiB 就是 88–99%
+  占用。被杀的调用没有阶段计时，数据无法区分"等上游"与"GC 抖动到上限"。60 s 自报就是用来
+  在下一次分开这两者的。
+- **上游自身行为未经证实。** 400 只按状态码归类。响应体本来就在异常信息里，`NMG_DEBUG_ERRORS=1`
+  会记录它；不带该开关时，日志无法区分"余额不足"和"批量参数非法"。
+- **90 s 这个默认值没有任何记录解释过。** 这里把它当缺陷处理，而不是推翻某个决定。
+
+## 考虑过的替代方案
+
+- **调大 `maxDuration`。** 已是平台最大值 120 s。
+- **归因于 OPFS 初始化噪音。** `sqliteReady()` 有 memo，VFS 安装每个实例只发生一次，且异常被
+  SQLite 模块吞掉。重复的日志行来自并发实例，不是重试，也没有可测的时间成本。
+- **把上游拒绝当作超时的原因。** 非可重试状态由客户端立即返回，而且那批拒绝比最后一次超时
+  晚 41 秒才出现。
+
+## 后果
+
+- 上游变慢现在只损失得分，不损失调用：缺失向量的部分用词重叠打分，检索仍然作答。
+- 批量融合对健康的上游也更便宜：一次往返取代最多四十次，延迟与上游负载同步下降。
+- 写入路径保持原有宽松度。文档不设预算，大 Add 不会被 query 预算截断，而由单次超时与
+  批量大小约束。
+- 运维可以从 `/health limits` 直接读到三个约束数字；活过 60 秒的请求会在仍存活时先自报。
+- 未处理：单次调用常驻内存 762–1014 MB。若实例上限是 1 GiB，这就是下一个要查的失败，
+  而慢请求自报会告诉我们是内存还是等待。