Skip to content

service-messaging on Postgres: sys_notification_delivery.claimed_at is a real (binary32) column, so every ack() fails the claim check and the inbox row is re-delivered every 131 s forever #23122

Closed

Description

@baozhoutao

Summary

On a Postgres database whose sys_notification_delivery table was created by @objectstack/driver-sql ≤ the release that still mapped number → table.float() (verified on 17.3.0), the epoch-ms columns claimed_at, next_attempt_at, last_attempted_at are physical real (IEEE-754 binary32).

A 13-digit epoch-ms value cannot be represented in binary32. Around today's timestamps the spacing between adjacent representable values is 131 072 ms, so whatever claim() writes into claimed_at reads back rounded to a multiple of ~131 s.

SqlNotificationOutbox.ack() then compares the stored value with the in-memory claim credential using strict equality:

if (current.claimed_by !== claimed.claimedBy || current.claimed_at !== claimed.claimedAt) {
  throw new NotificationAckError(notificationAckLostClaimMessage(...), 'DELIVERY_NOT_ELIGIBLE');
}

That comparison can never succeed, so every ack is refused as a "lost claim". NotificationDispatcher.ackAttempt() swallows DELIVERY_NOT_ELIGIBLE with a warn, so:

  1. the inbox channel has already inserted the sys_inbox_message row (the send succeeded),
  2. the delivery row stays in_flight with attempts = 0 (ack never writes, so it never reaches dead),
  3. the visibility-timeout reap (claimed_at < now - claimTtlMs) also runs on the quantized column, so it releases the row once per 131 072 ms step,
  4. the row is claimed and sent again → another sys_inbox_message row → back to 2.

Each stuck notification is re-delivered ≈ 659 times per day (86 400 s ÷ 131.072 s), indefinitely.

Production evidence (PostgreSQL 16, platform 17.3.0, 3 app replicas)

  • information_schema.columns for sys_notification_delivery: claimed_at, next_attempt_at, last_attempted_at, attempts, partition_key are all real.
  • sys_notification_delivery status distribution: in_flight / inbox = 301 with max(attempts) = 0; success / inbox = 1097.
  • Write interval of one notification into sys_inbox_message: 2:10.79 – 2:11.32, stable.
  • Top-10 notifications in the last 24 h: 659 rows each. Oldest stuck notifications (created 2026-09-16): ~17 550 inbox rows each.
  • sys_inbox_message grew to ~3.6 M rows / ~1.8 GB in a month, ~180 k rows/day, while the producing business table received a few thousand rows total. n_tup_del = 0, i.e. nothing is rolled back or deleted — it is pure re-delivery.
  • The only DB clients are the app replicas; no external writer.

Quick numeric check of the quantization:

const t = Date.parse('2026-10-12T13:00:00Z'); // 1791810000000
Math.fround(t);                                // 1791809945600  (Δ = -54 400 ms)
// spacing between neighbouring binary32 values at this magnitude: 131 072 ms

What is already fixed upstream, and what is not

Suggested fixes

  1. Detection / migration for existing real columns of the NUMERIC_VALUE_TYPES family (at minimum the platform's own epoch-ms columns on sys_notification_delivery and sys_http_delivery): a boot warning from drift detection plus an operator-run os migrate step (ALTER COLUMN … TYPE numeric(65,30)), consistent with the [Decision] 老客户把「选一个人」的字段改成「选多个人」时,平台该自己动客户的库,还是只报警要人来动?(#11535 的自动迁移半边) #11700 policy.
  2. Make the claim credential robust to the column: e.g. use a random claim token (text) instead of claimed_at for the CAS, or compare after a round-trip read of the value written by claim() rather than against the in-memory now.
  3. Never let a refused ack loop silently forever: a delivery that has been reaped N times without a recorded attempt should be surfaced (error log / metric) or moved to dead, instead of re-sending with attempts = 0 indefinitely.
  4. Consider checking sys_http_delivery for the same pattern (its time columns are number too).

Workaround we are applying

ALTER TABLE sys_notification_delivery
  ALTER COLUMN claimed_at        TYPE numeric(65,30),
  ALTER COLUMN next_attempt_at   TYPE numeric(65,30),
  ALTER COLUMN last_attempted_at TYPE numeric(65,30);
UPDATE sys_notification_delivery
   SET status = 'success', claimed_by = NULL, claimed_at = NULL, attempts = 1
 WHERE status = 'in_flight';

(17.3.0's read path already coerces numeric strings back to JS numbers via numericFields, and its drift detector does not flag the type change.) Followed by de-duplicating sys_inbox_message per (notification_id, user_id).

Activity

  1. objectstack-fleet commented on Oct 13, 2026

    @objectstack-fleet
    Contributor

    Triage: first grade, bug · priority:p1 · domain:services · area:workflow, into pm:queue. The claim check must survive the column it reads. No migration of existing columns

    Triage seat (objectstack-wide, seat post #6015) · session_01AavokzJ5DndAwitDXvKy4U · 2026-10-13T01:54Z. ⛔ Not a claim, ⛔ not a dispatch.

    Thank you for the production evidence and the arithmetic. Re-read on origin/main now: sql-outbox.ts still verifies a claim with claimed_at: now as an equality predicate (:189, :227), and ack() still compares claimed_at with !== (:269).

    • Why p1: it is a live production loop with no end state. Every affected Postgres deployment re-sends each stuck inbox notification about 659 times a day, and its inbox table grows without bound. Reach: any schema created before [finding] The NUMERIC column family diverges from driver-sql in both migration formats — driver real, generators numeric, and rating is real against integer #16318's column table, which is new tables only. A workaround exists, as the report shows, so it is not p0.
    • Direction: the claim credential round-trips exactly, whatever numeric column type holds it.
      • The claim's verification and ack() stop comparing a client-side epoch-ms value against a number column by equality.
      • Two acceptable shapes: a claim token that does not depend on numeric precision, or the value read back from the store. The dev measures which one fits both drivers and states the choice.
      • The sibling sql-http-outbox.ts (sys_http_delivery) gets the same fix in the same PR.
      • Census, same PR: every platform claim or lease check that compares a stored epoch-ms number column by equality. A same-class hit is fixed here. ⛔ No single-point card for it.
      • Pins:
        • a driver double, or the live PG cell, whose number column quantises like real (Math.fround). ack() succeeds, and the row reaches success after one send;
        • the control: a numeric column still acks.
      • An in_flight row stuck today is reaped and claimed again under the fixed code. Its next ack then succeeds and the loop ends without an operator act. The PR shows this with one pin.
    • ⛔ Not in this card:
    • Release: there is no 17.x maintenance line, by ruling. The fix ships on the v18 line, and your SQL workaround covers 17.x until you upgrade.
    • Triage: lands in packages/services/service-messaging/src/sql-outbox.ts and sql-http-outbox.ts (domain:services); rationale: a CAS on a lossy column can never succeed.
  2. added
    area:workflowApprovals and automation — the work that runs without a person driving it
    bugSomething isn't working
    priority:p1High: required for production / M2
    and removed on Oct 13, 2026
  3. objectstack-fleet commented on Oct 13, 2026

    @objectstack-fleet
    Contributor

    Claim: PM loop round 5 · 2026-10-13T02:02Z
    Session: session_01FzQy26KznSa5j2gnf3AzsE
    Account: zhuangjianguo (the seat's linked user as GET /user answers it; the card's assignee)
    Branch: claude/issue-23122-outbox-claim-credential
    Worktree: objectstack-issue-23122
    Domain: domain:services
    Seat: domain:services#2 (seat post #21118)
    Queue-jump: the maintainer's direct dispatch, verbatim 「23122 插队」, in this seat's session chat at 2026-10-13T02:00Z. It goes first in the pick order; the claim protocol is unchanged.
    File surface: packages/services/service-messaging/src/sql-outbox.ts and sql-http-outbox.ts (the claim verification and ack()), their tests under packages/services/service-messaging/, one .changeset/23122-*.md; plus any same-class claim or lease check the census finds (equality on a stored epoch-ms number column). A hit outside service-messaging is fixed in this PR and declared to its lane before the PR leaves draft (stop on breach; explain in the report)
    Container & model: M (two outboxes, one credential shape measured on both drivers, plus a census), mode:subagent, model: default — dispatch-gates --tier --repo objectstack-ai/objectstack: "no path-derived mandate … The tier stays the PM's per-card judgment call"
    Clause-②: no — a runtime fix to the outbox claim credential; no published accept set or public surface moves.
    Responsibility: service-messaging's SqlNotificationOutbox / SqlHttpOutbox (the platform's own code) verifies a claim by exact equality on an epoch-ms number column | none: drift detection does not flag the real column, and existing columns are not migrated by ruling (#16318: new tables only) | every Postgres deployment whose sys_notification_delivery / sys_http_delivery tables were created before #16318's column mapping (the reporter's 17.3.0 production: 659 re-deliveries a day per stuck notification)
    Thread-read: 6136365627
    Serial constraints cleared: no pm:dispatched claim declares service-messaging (23 cards read), and no open PR touches packages/services/service-messaging/ (11 open PRs' file lists, read at this claim). The last landing on these files was a7a48b784 (#22045), not today. In flight in this lane: #23093 (PR #23114, in the merge queue) on plugin-security, disjoint.


    Generated by Claude Code

  4. objectstack-fleet commented on Oct 13, 2026

    @objectstack-fleet
    Contributor

    os-dev-report
    {
    "issue": 23122,
    "status": "done",
    "branch": "claude/issue-23122-outbox-claim-credential",
    "pr": "#23138",
    "session": "session_01FzQy26KznSa5j2gnf3AzsE (shared with the dispatching seat, mode:subagent; identity = the branch)",
    "premise_still_valid": true,
    "summary": "SqlNotificationOutbox and SqlHttpOutbox now hand out claimedAt as the claimed_at value the store read back after the claiming UPDATE, not the in-memory now. The claim read-back filters on candidate id, holder and status only, without the claimed_at: now equality. ack() is unchanged in code: its read half now compares two reads of one cell, and its compare-and-set binds the stored value. No schema, type or export change. Credential shape chosen: read-back, not a token. A token needs a new column on both platform objects and a new member on the published credential types, which the claim's Clause-② no rules out. Read-back was measured exact on live PostgreSQL 16.15 real and numeric columns, and on SQLite and memory. Live PG16 at bcebd84: H1 confirmed (the ack read half is the failing check; the JS read-back is the shortest round-tripping decimal, e.g. 1791810100000 for now=1791810012345, so ack is refused with DELIVERY_NOT_ELIGIBLE and the row stays in_flight with attempts 0, on both outboxes). H2 falsified on PG16: the claim verification find matched, because node-postgres parameters are coerced to real server-side, so the reporter's loop takes the ack path. The predicate is removed anyway, because the equality holds only when the store coerces the comparand. H3 confirmed: the reap does not fire at TTL+1 and fires within one 131072 ms step. On the fixed code the same server measured: real-column acks land; a stuck row is reaped, re-claimed and acked, and a later claim takes nothing; another node's re-claim still refuses the late ack with DELIVERY_NOT_ELIGIBLE. Census: no same-class hit outside service-messaging. Trade, stated in the PR's Acceptance notes: two CONCURRENT claim() calls with the same nodeId over overlapping candidates are no longer told apart by claimed_at. The dispatcher never does this, and before they were told apart only when their now differed by at least 1 ms. Not measured: PostgreSQL 11 or older, where extra_float_digits defaults to 0.",
    "tests": "All at the final head 82c0b14 unless named. (1) pnpm --filter @objectstack/service-messaging test under os-verify-lock: 'Test Files 49 passed (49) / Tests 564 passed (564)', VERDICT command-exit 0. typecheck: tsc --noEmit plus the scripts program clean, VERDICT command-exit 0; tsc --listFiles includes the new test file (count 1). (2) New pin file src/outbox-claim-credential-lossy-column.integration.test.ts, 15 tests. A real ObjectQL+SqlDriver(better-sqlite3) engine sits behind a double with Postgres real semantics: binary32 store, comparand coercion, shortest-decimal read. A fidelity leg pins the three live PG16 readings. Per outbox, on the real double, an exact column and memory: one send and one ack reach success and three later reap windows send nothing; a claim lost to another node refuses the late ack ({name, code: DELIVERY_NOT_ELIGIBLE}) and the holder's ack lands. Real double only: a row stuck behind the pre-fix credential is sent exactly once more over five dispatcher-shaped passes. (3) Ablation, committed first at dee1e11, via scripts/ablation-replace.mjs (anchor hit and blob change verified) inside a trap restore. Leg A, sql-outbox.ts: the old claimed_at: now find and claimedAt: now restored (anchor x2, blob 8821ed0806e6 to ef1e0996acd3). Leg B, sql-http-outbox.ts: the same, nested (blob ceb424363276 to 31d0adc06902 to c9cdfee54d1d). Each leg gave 'Tests 3 failed | 12 passed (15)': exactly the three real-column legs of that outbox went red. 'AssertionError: promise rejected "NotificationAckError: ..." instead of resolving / Caused by: ... is no longer held by the claim this ack completes ... Serialized Error: { code: DELIVERY_NOT_ELIGIBLE }' (HttpAckError for leg B), plus the stuck leg 'expected [ ...(5) ] to deeply equal [ Array(1) ]', the same id sent on all five passes. Exact and memory controls stayed green. Restore proven: blobs equal HEAD (8821ed0806e6, ceb424363276) and git diff HEAD is empty. No dist involved: the pins import ./sql-outbox.js from src. (4) Live PG 16.15 one-off measurement on a private cluster, port 54731, stopped and deleted afterwards. Pre-fix bcebd84: 3 of 3 non-round instants refused per outbox; numeric control acks. Fixed e2af29f, source unchanged since (git diff --stat e2af29f HEAD over the 4 source files is empty): all ack; stuck-row and lost-claim legs as in the summary. (5) Gates: dispatch-gates --commands (no paths) derived 66 at e97bbb7 and at 82c0b14 (the PM's list of 65 plus pnpm check:dispatcher-error-vocabulary). Union at the final head 82c0b14: 66 of 66 EXIT=0, exit captured before any pipe, per-command log. check:i18n ('check-i18n-bundles: OK (10 package(s) ...)') and check:dual-build-cjs-loads ('108 published require entry point(s) across 67 package(s) load') were measured after building their prerequisite closure. The first union at e97bbb7 had check:query-options-erasure exit 1 ('test surface grew 236 to 240'), caused by the new double's erased options; fixed in 82c0b14 by typing them; now '... ratchet holds ... test surface: 236 site(s)'. dispatch-gates --ran: '66 derived famil(ies) accounted for, 66 run, 0 NOT-MEASURED'. Lint: NOT MEASURED locally, a repo-wide scan owned by CI. Also check:engine-double-contract EXIT 0 on the new double. CI: in_progress at report time; not waited on.",
    "mcp_calls": "0",
    "api_writes": "2 relay dispatches (POST /repos/objectstack-ai/objectstack/dispatches, run as objectstack-fleet[bot]). (1) pr_create = POST /repos/objectstack-ai/objectstack/pulls (draft) + POST /repos//issues/23138/assignees [zhuangjianguo]; the run read back 11615 bytes sent and 11615 stored, identical. (2) comment = POST /repos//issues/23122/comments (this os-dev-report). Label writes: 0. The dispatch named none, and skip-changeset does not apply because the package publishes. git push x7 (not REST).",
    "open_questions": [],
    "out_of_scope_findings": [
    "carrier: none (承接者:无) · noted, not filed · PostgreSQL 11 and older: extra_float_digits defaults to 0 (6 significant digits), so the compare-and-set that binds the read-back value would miss on a legacy real column. Not measured; versions past upstream support. Recorded in the PR's Acceptance notes.",
    "carrier: none (承接者:无) · noted, not filed · the census found one adjacent shape out of class: service-storage metadata-store.ts:732, the upload-session progress compare-and-set. It compares byte counts, not epoch-ms, and its comparand is already a store read-back. A legacy real column there would store sizes over 2^24 lossily; that belongs to the ruled 'new tables only' family, not measured.",
    "PR-body amendment for the seat (dev writes the body once): the Verification section says the final union re-run 'was in progress when this PR opened'. Its result is 66 of 66 EXIT=0 at 82c0b14, with check:i18n and check:dual-build-cjs-loads measured after their prerequisites were built. Optional edit: replace that sentence with this result."
    ]
    }


    Generated by Claude Code

  5. objectstack-fleet commented on Oct 13, 2026

    @objectstack-fleet
    Contributor

    Seat ACCEPT: PR #23138 at 82c0b1457 · read-back claim credential

    domain:services seat 2 · session_01FzQy26KznSa5j2gnf3AzsE · 2026-10-13T03:32Z, under claim 6136508167 (queue-jump, the maintainer's 「23122 插队」). The dev's report is 6137555861. Checked on GitHub and on origin/main, not from the report.

    Checklist

    • PR form: draft, base main, assignee zhuangjianguo. The first line is Fixes #23122, then Clause-②: no. The only closing keyword is on service-messaging on Postgres: sys_notification_delivery.claimed_at is a real (binary32) column, so every ack() fails the claim check and the inbox row is re-delivered every 131 s forever #23122.
    • Scope: 6 files, +547 / -23, all in packages/services/service-messaging. Not governed, and under the 3000-line threshold. The code change is in sql-outbox.ts and sql-http-outbox.ts:
      • the claim read-back drops claimed_at: now from its where;
      • claimedAt becomes r.claimed_at, the value the store returned.
      • http-outbox.ts and outbox-dispatcher-scope.ts change doc comments only.
      • No type, export or schema moves. ClaimedDeliveryRecord and HttpClaimCredential are unchanged, so Clause-②: no stands, and no contract review is owed.
    • The claiming write is still guarded. The update keeps status: 'pending' in its sweep predicate, so a row is claimed once.
      • The named trade: two concurrent same-nodeId claims are no longer told apart by claimed_at. Read on origin/main, it is unreachable today.
      • Each dispatcher mints its own node id (notify-PID-RANDOM / http-PID-RANDOM in messaging-service-plugin.ts), and its loop serialises ticks (a wake during a tick queues one follow-up).
      • It is recorded in the PR's Acceptance notes.
    • Changeset: @objectstack/service-messaging: patch (the package publishes). Read sentence by sentence against the diff:
    • Evidence:
      • live PostgreSQL 16.15: pre-fix, 3 of 3 non-round instants refused per outbox, with the numeric control acking; post-fix, all ack;
      • the new pin file (15 tests) covers the real-semantics double, an exact column and memory, with a lost claim to another node still refused and a stuck row sent exactly once more;
      • ablation legs A and B each went red on exactly their outbox's three real-column legs, and the restore was proven by blob;
      • service-messaging passes 564 of 564;
      • the census found 4 hits, all in service-messaging, with the positive control sql-outbox.ts:189 present.
    • CI at 82c0b1457 (latest run per name): 34 success, 6 skipped (expected roster), 0 red.
    • Writes: mcp_calls 0; the relay writes were pr_create and the report.
    • H2 corrected in public: the dispatch's hypothesis that the verify find also misses on real was falsified on PG16 (node-postgres coerces the parameter server-side). The predicate is removed anyway, because it is correct only when the store coerces.

    Out-of-scope findings

    • PostgreSQL 11 and older (extra_float_digits 0): Acceptance notes. Not measured, on versions past upstream support.
    • The service-storage upload-session compare-and-set: dropped. It compares byte counts against a read-back comparand, so it is out of class. A legacy real column there belongs to the ruled "new tables only" family.

    Landing: pr_ready + automerge_enable through the relay. This seat follows it to MERGED.


    Generated by Claude Code

  6. objectstack-fleet commented on Oct 13, 2026

    @objectstack-fleet
    Contributor

    Landed · PR #23138 merged through the merge queue at 2026-10-13T03:58Z as 5d63c37c56, and that commit is on origin/main (read 2026-10-13T03:59Z). domain:services seat 2 · session_01FzQy26KznSa5j2gnf3AzsE, under claim 6136508167 (the maintainer's queue-jump) and ACCEPT 6137592480.


    Generated by Claude Code

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    area:workflowApprovals and automation — the work that runs without a person driving itbugSomething isn't workingdomain:servicespriority:p1High: required for production / M2

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions