fix(service-messaging): reap once per dispatcher tick, back off while idle, wake on emit - #17622
Conversation
… idle, wake on enqueue Claude-Session: https://claude.ai/code/session_c5c0ce54-bb9c-478c-9e5b-cf44b80d4569 Co-authored-by: Claude <noreply@anthropic.com>
…it and once-per-tick reap recovery Claude-Session: https://claude.ai/code/session_c5c0ce54-bb9c-478c-9e5b-cf44b80d4569 Co-authored-by: Claude <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_c5c0ce54-bb9c-478c-9e5b-cf44b80d4569 Co-authored-by: Claude <noreply@anthropic.com>
… dispatcher probes for A store without reap() keeps working: its claims keep reaping as before. Claude-Session: https://claude.ai/code/session_c5c0ce54-bb9c-478c-9e5b-cf44b80d4569 Co-authored-by: Claude <noreply@anthropic.com>
📓 Docs Drift CheckThis PR changes 1 package(s): 1 hand-written doc(s) NAME something this change touched and may need an implementation-accuracy re-verification:
⛔ 3 release-owned page(s) also name something this change touched. These are read-only:
What this run could not see
Coarse fallback — 5 page(s) merely mention a changed package (the pre-#9192 predicate, kept for the deliberately-wide backstop): Which tree this was computed onThis run read A worktree cut from an older # while this PR is open — GitHub drops the merge commit once it closes
git fetch origin ce6d45da6b6bcd01cdef14bd0317831f6b8b693b && git checkout ce6d45da6b6bcd01cdef14bd0317831f6b8b693b
# afterwards, rebuild it from the two parents, which stay fetchable
git fetch origin 0918c441188cae8c3990ac8cb38dbb6dd6e7b6e4 ff0ba83a2555402db3214ca7082b0824acffbde1 && git checkout -B drift-repro 0918c441188cae8c3990ac8cb38dbb6dd6e7b6e4 && git merge --no-ff ff0ba83a2555402db3214ca7082b0824acffbde1
node scripts/docs-audit/affected-docs.mjs --json 0918c441188cae8c3990ac8cb38dbb6dd6e7b6e4
|
… (223 -> 222) SqlNotificationOutbox's two inline reap UPDATEs became one reapExpired() helper, so the census counts one fewer write call site. Claude-Session: https://claude.ai/code/session_c5c0ce54-bb9c-478c-9e5b-cf44b80d4569 Co-authored-by: Claude <noreply@anthropic.com>
PM 复核(maintainer direct dispatch,Session
|
| 项 | 读数 | 结论 |
|---|---|---|
| 改动面 | 14 个文件;packages/spec/src/** 0;受治理面(AGENTS.md / CLAUDE.md / .claude/** / docs/adr/**)0 |
Clause-②: no 成立 |
| 两份审计普查文档 | content/docs/permissions/tenant-audit-census.mdx、docs/audits/…counts.md:reap 合并使写入调用点 223 → 222,由 check-tenant-audit-census 要求重测 |
合理,非受治理面 |
| changeset | @objectstack/service-messaging: minor;INotificationOutbox.reap() 与 ClaimOptions.skipReap 均为可选 |
非破坏性 |
| reap 移到分区锁外 | runTick 开头每跳一次;reap 是条件更新 status='in_flight' AND claimed_at < now - claimTtlMs,谓词不含分区 |
安全——锁内跑时本来就在改写其他分区的行,ack 对已被回收的认领匹配不到(#11859) |
| 旧 outbox 兼容 | if (outbox.reap) 才置 reapedForTick;未实现 reap() 的存储 skipReap=false,每次领取照旧自 reap |
兼容 |
| 退避计时器可被停掉 | setTimeout 链;stop() 置 running=false、清 tickRequested、clearTimeout、等待进行中的一跳 |
满足——这正是 cloud 侧「归档驱逐 kernel」修复所依赖的行为 |
| 唤醒 | emit() 经 setOutbox(outbox, { onEnqueued }) 调 wake(),重置空闲计数并立即排一跳 |
满足验收 2 |
开放问题的裁定:空闲退避上限默认 30 秒(选项 A)
- 本进程内的
emit会立即唤醒,所以上限只推迟无人通知的工作:延迟重试、静默时段、摘要、其他进程写入的行、崩溃节点的认领回收 - 这几类对 30 秒不敏感,而空闲往返从每秒约 28 条降到约 0.57 条(约 1/50)
- 运维可按插件用
dispatchMaxIdleIntervalMs调低 - 崩溃节点认领的回收上界相应变为
claimTtlMs + 30s,已在 PR 正文写明——接受
席位带回的范围外发现
HttpDispatcher/sys_http_delivery同形状(每跳 16 条、固定 500ms、无退避)→ PM 另立卡,待本 PR 合并后复用同一模式派发DbQueueAdapter.claimBatch队头饥饿 → 补到 service-queue:DbQueueAdapter.claimBatch按priority, scheduled_for排序,而sys_job_queue的声明索引不含priority—— 排序首键落空,恒定 1s 轮询每跳吃一次临时 B-tree 排序 #17612(该卡正文未提)
下一步:CI 全部结束且无失败 → 转 ready → 入合并队列。有红按日志回派同一席位。
|
范围外发现的去向补全:
|
Closes #17610
What changed
NotificationDispatcherstops paying for an empty outbox on every tick.INotificationOutboxgains an optionalreap(opts), andClaimOptionsan optionalskipReap. The dispatcher runs the reap once, at the start of the tick and outside any partition lock, then claims every partition withskipReap: true. Directclaim()/claimDigest()callers are unchanged: withoutskipReapthey reap exactly as before.intervalMs(500 ms) up tomaxIdleIntervalMs(new, default 30 s, plugin optiondispatchMaxIdleIntervalMs). A tick that claims anything snaps back tointervalMs, and a failed tick counts as idle, so a broken store is not hammered. The loop is now a self-rescheduling unref'dsetTimeout, measured from tick start, with the same never-two-ticks-at-once guard.MessagingService.setOutbox(outbox, { onEnqueued })fires once peremit()that enqueued at least one delivery, which is the one fan-out site that writes delivery rows (enqueueDeliveries).MessagingServicePluginpoints it at the newNotificationDispatcher.wake(). A wake ticks immediately; a wake during a running tick queues exactly one follow-up tick for when it settles, and any number of wakes in that window collapse into one.Premise check against
origin/main(3ef96b4)The card's arithmetic is right. I measured it with a throwaway probe on a real
ObjectQL+SqlDriver(better-sqlite3), counting both theIDataEnginecalls and the driver's own knexqueryevents, over 5 idle ticks with 8 partitions:SELECT id … digest_key IS NULL AND partition_key = ?SELECT id … digest_key IS NOT NULL AND partition_key = ?Loop cadence while idle, with default options and ticks treated as instant: 1,201 ticks / 38,432 statements over 10 minutes before, 24 ticks / 408 statements after. Real ticks take time on remote Turso (the card measured about 1.1 s at 32 statements), which only lowers both numbers. In the steady idle state this is 17 statements every 30 s, about 0.57 statements/s, against the measured ~28/s.
No objection to the card's premise. The reap has no correctness reason to run per partition. Its predicate names no partition, and the partition lock never covered it: a reap under partition p's lock was already rewriting rows in every other partition.
Why reaping once per tick does not stretch claim-TTL recovery
in_flightrows are still recovered within one tick ofclaimTtlMspassing.claim()only takespendingrows, and an ack whose claim was reaped is refused by its compare-and-set (INotificationOutbox.ack()carries nonodeId, so its compare-and-set can prove a claim exists but not whose #11859).claimTtlMs+maxIdleIntervalMs, which with defaults is 5 s + 30 s. The fixed loop gaveclaimTtlMs+ 500 ms. That is the stated trade (below).Latency bound
emit()wakes the dispatcher and the new rows go out on the tick that wake starts.maxIdleIntervalMs(30 s by default). This covers a deferred delivery coming due (the retry schedule's later steps, quiet hours, a digest window), a row enqueued by a process that does not run this dispatcher, and a crashed node's expired claim. The first retry (~1 s) stays on time: the failed attempt claimed a row and reset the backoff, and the next ticks come 0.5 s and then 1 s later.dispatchMaxIdleIntervalMs: dispatchIntervalMsrestores the fixed interval.Compatibility
reap()is optional onINotificationOutbox, following the capability-probe patternDispatchLockHandle.renew?/isHeld?already use in this file. A custom outbox written before it keeps working: the dispatcher probes forreap, and when it is absent, claims are not told to skip, so each claim reaps as before. That is correct, just at the old per-claim cost. A test pins this fallback (see A4 below). Both built-in stores implementreap(). The changeset isminor(additive API:wake(),maxIdleIntervalMs,dispatchMaxIdleIntervalMs,reap?,ReapOptions,setOutbox's second argument), and nothing is declared breaking.I first made
reapa required member.check-adr-0087-registrationrightly refused that shape: a changeset carrying a FROM/TO prescription cannot claimno-migration-prescription, and no ledger category fits a runtime TS interface member. Making the member optional removes the break instead of arguing with the gate. Its green reading is below.Acceptance, item by item
src/dispatcher-idle-cost.integration.test.ts, realObjectQL+SqlDriver, 8 partitions, 10 idle ticks: exactly 10 reap UPDATEs, and total engine calls at most10 × (1 + 2 × 8). The legs recovers a crashed node's expired claim and delivers it within ONE tick and leaves a claim that has NOT expired alone pin recovery and the TTL floor. The leg an outbox without reap() keeps working pins the compatibility fallback.delivery-claim-tenant-audit.integration.test.tsgains areap()leg: it reaps across organizations with no tenant-audit finding, with the file's positive control.src/dispatcher-idle-backoff.test.tsruns on fake timers. It checks the exact gap sequence (1 s, 2 s, 4 s, 8 s, 16 s, 30 s, then 30 s), the 30 s default, that a ceiling at or belowintervalMsdisables the backoff, the one-interval bound for an unannounced row plus the snap-back to 500 ms, thatwake()ticks at the same fake instant, that wakes during a running tick collapse to one follow-up, thatstop()cancels the timer, and thatMessagingService.emit()wakes a wired dispatcher while an emit that enqueues nothing does not.src/plugin-enqueue-wakes-dispatcher.test.tsboots the composedMessagingServicePluginon a real kernel and engine withdispatchIntervalMs= 60 s, so no timer tick can happen during the test. A row written straight into the table (no emit, no wake) stayspendingafter a real 500 ms wait. That is the negative control. Thenemit()delivers both rows.dispatcher-idle-cost.integration.test.tsis the count test. Its leg rows enqueued after an idle stretch go out on the very next tick uses 16 rows hashed across several of the 8 partitions plus a two-row digest window: all delivered in one tick, and the digest sent as one message.@objectstack/service-messagingsuite is green, including the INotificationOutbox has no cancellation, andack()on an unclaimedpendingrow silently succeeds in both implementations #11453 /INotificationOutbox.ack()carries nonodeId, so its compare-and-set can prove a claim exists but not whose #11859 ack and claim-ownership suites, digest, and the flaky: a vitest worker teardown race (EnvironmentTeardownError: Closing rpc while onUserConsoleLog was pending) fails app-showcase with 334/334 tests passing #9371 shutdown test.service-automation's three notify integration files, which drive the realNotificationDispatcherthrough the rebuiltdist, are green too.Reverse verification (ablations, each restored from HEAD and proven by blob hash plus an empty
git diff HEAD)The ablation run was on HEAD
f368fd0aa. Every mutation was confirmed on disk by occurrence counts before its run.skipReap: trueeven when the outbox has noreap()emit()no longer callsonEnqueuednextIntervalMsalwaysintervalMs)A3 leaves a row nobody announced waits at most one backed-off interval green, as expected: that leg pins an upper bound, and a fixed 500 ms loop meets it trivially.
Commands and results
pnpm --filter @objectstack/service-messaging exec vitest run --maxWorkers=2: 37 files, 389 tests passed (HEADf368fd0aa)pnpm --filter @objectstack/service-messaging typecheck: exit 0. The packagetsconfigincludes all ofsrc, so the new tests are type-checked.pnpm exec turbo run build --filter="@objectstack/service-automation^..." --concurrency=2, thenvitest runonservice-automation/src/builtin/notify-{delivery-outcome,organization-stamp,zero-delivery-visibility}.integration.test.ts: 3 files, 18 tests passed--no-inline-config --format json) over the 11 touched.tsfiles: 11 files, 0 errors, 0 warnings. This narrowing is sound:eslint.config.mjsnever enables type-aware linting (noparserOptions.project), so this diff cannot move the verdict on any untouched file.node scripts/check-adr-0087-registration.mjs --base origin/main: ✓ no declared-breaking changeset.check-changeset-no-major✓.check-empty-changeset✓. All three--self-tests ✓.node scripts/pm/dispatch-gates.mjs --commands): all 94 run with exit codes recorded;--ranreconcile reads 94 derived, 91 run, 3 NOT-MEASURED, 0 UNRUN.check-tenant-audit-censuswent red on this diff: the reap consolidation removed one write call site (223 → 222).ff0ba83a2re-measures the census page and its prose counts; the gate and its--self-testboth exit 0 atff0ba83a2.check:i18n,check:type-check-debtandcheck:dual-build-cjs-loads(exit 3; they need the CLI closure or a full-repo build, which was out of bounds for this seat).check:skill-examplesexits 1 but with its own refusal text,packages/client-react/distholds no.d.ts; this diff touches no marked example.check:merge-driverexits 1, failing the same twocheck-regen-pending --self-testcases on a cleanorigin/main0918c4411checkout on this host. It is not caused by this diff, which touches no merge-driver or regen surface.f368fd0aa; the 31 families the census files added ran atff0ba83a2.Declared: the heavy commands above ran through
scripts/pm/os-verify-lock.sh, which reported UNLOCKED (declared). This host has no usableflock, so nothing was serialized.Acceptance notes (out of scope, not changed here)
indexes— every declared secondary index is absent on production Turso tenant databases, so hot polling queries full-scan #17609 is not addressed here (remote-mode driver never materializes object-level indexes). service-messaging: fan-out writes anemaildelivery for a tenant with no email transport — it dead-letters on its first attempt and is kept 90d, so the hot outbox grows ~1 dead row per notification #17611 is not addressed here (dead-letter email delivery rows).HttpDispatcherhas the identical shape. Measured with the same kind of probe onSqlHttpOutbox, 8 partitions: 16 statements per idle tick (8 reap UPDATEs + 8 SELECTs), fixed 500 ms, no backoff, againstsys_http_delivery. It lives in the same plugin, next to the dispatcher fixed here. The same two changes (reap?+skipReap, backoff + wake fromenqueueHttp) would apply. I did not change it, because the claim's declared file surface is the notification dispatcher. I found no open card for it and have reported it to the PM for filing.DbQueueAdapter: service-queue:DbQueueAdapter.claimBatch按priority, scheduled_for排序,而sys_job_queue的声明索引不含priority—— 排序首键落空,恒定 1s 轮询每跳吃一次临时 B-tree 排序 #17612 remains open and already covers the sort-key/index mismatch and the constant 1 s poll. Separately,claimBatchapplies its due-time filter (scheduled_fornot after now) in JS afterLIMIT batchSize × 3, sorted bypriorityfirst. I reproduced head-of-line starvation with a throwaway probe using that package's own fake engine (it honoursorderByandlimit), batch size 10. With 29 future-scheduled priority-1 jobs, a due priority-100 job is processed; with 30,pollOnce()processes 0 and the due job waits until the future ones come due. I reported this to the PM; it is not changed here.Generated by Claude Code