Authenticated data requests issue ~20 DB queries in ~17 sequential legs — per-request auth/session/localization/metadata resolution has no cross-request caching, costing ~1.5s/request on remote Postgres #10757

⚠️ 2026-09-01:重述停放理由。 本卡此前挂 pm:blocked,卡体里没有任何 Blocked-by: 行 —— 停放理由只活在一条评论里(Blocked-by: #11633),而解锁扫描只读 body。本次把理由写进 body,并把标签改为 pm:on-hold,因为那个 blocker 的活已经干完了,剩下的是一次测量,不是一个依赖。

Restart-when: 在一台远程 Postgres 部署上按下文「Per-query evidence」的方法重测本卡的原始症状(GET /api/v1/data/:object?$top=1 的 db 查询计数与 handler 用时),并把读数贴回本卡。若已达 cloud#1521 的 ≤200ms 门 ⇒ 关卡;若未达 ⇒ 按新读数重定范围,本卡的 8 条修法清单里哪几条还没被 #11633 的支线覆盖,就剩哪几条。
Restart-touch: packages/core/src/security/resolve-authz-context.ts, packagesives/rest/src/rest-server.ts, packages/plugins/plugin-auth/src/auth-manager.ts

⛔ 原 Blocked-by: #11633 已不成立。 直接读 #11633 的当前状态(⛔ 不取本卡对它的转述):设计 2026-08-24 交付,维护者 2026-08-25 ACCEPT 并裁完四个分叉,卡本身已从 needs-user-decision 转为 tracking 协调父卡;sub_issues_summary = 5 / 5 完成 —— #11966(leg C)、#11967(leg D)、#11968(substrate)、#11969(ADR 转换)、#11971(leg B,授权缓存,即「设计真正要做的那条腿」,2026-08-30T14:44Z 关闭)全部关闭。

⇒ 本卡 2026-08-28 那次巡检问对了问题(「clearing that blocker does not hand this card work — it hands #11633 work」),只是当时最后一个子卡还没关。现在关完了,所以本卡欠的不是等待,是一次读数。

⚠️ NOT MEASURED,且本仓测不了:cloud#1521 的 ≤200ms 门今天是否已经通过、以及放置问题(cloud#1518)。仓内没有任何命令能到达部署数据。能测的人:repo:cloud 席,或握有该部署的运维。⛔ 在读数回来之前,不得据仓内任何数字宣称本卡已解决。

Found while root-causing objectstack-ai/cloud#1518 (control plane pays ~1.5s of server time on EVERY authenticated DB-touching request on prod, ~6s on staging, independent of query shape and response size). Traced at cloud's pin 0c24898c. The mechanism is entirely in framework packages, so per cloud's contract-first rule it is filed here rather than worked around in the consumer.

The measurement

Staging (OS_SERVER_TIMING=true) for GET /api/v1/data/sys_user_preference?$top=1:

wall=6674ms server=[parse=0.05ms, db=6240.57ms, serialize=0.06ms, handler=5812.91ms, total=5813.63ms]

handler ≈ total and db ≈ handler — the request is essentially all DB time. db > total is explained by the db mark being a per-query SUM (PerfTiming.count, packages/drivers/driver-sql/src/sql-driver.ts installQueryTiming) over queries that partly overlap (see the parallel settings reads below).

Where the queries come from — one authenticated GET /data/:object?$top=1 issues ~20 queries in ~17 sequential legs

Every leg is a Neon round trip. At the ~50–90ms/query this deployment measures, ~17 sequential legs are the ~1.5s.

A. better-auth getSession — no caching anywhere (5 queries):

1. sys_session + 2. sys_user (better-auth core; cookieCache is not configured — zero grep hits in plugin-auth);
2. sys_user_permission_set, 4. sys_permission_set (FULL list, limit 50), 5. sys_member — the customSession plugin re-derives platform-admin/org roles on EVERY getSession call (packages/plugins/plugin-auth/src/auth-manager.ts ~2898–2960).

B. resolveAuthzContext / resolveUserAuthzGrants (8 queries, sequential) (packages/core/src/security/resolve-authz-context.ts ~330–560):
6. sys_member {user_id}; 7. sys_user_position; 8. sys_member {organization_id} (fellow-org, limit 1000); 9. sys_user_permission_set (duplicate of A3); 10. sys_position {name $in}; 11. sys_position_permission_set; 12. sys_permission_set {id $in}; 13. sys_user {id} for ai_seat (duplicate of A2).

C. Localization (3 queries, parallel): resolveLocalizationContext → 3× settings.get('localization', …) → loadRows is uncached by design (#10221 caches only FAILED reads), so 3 sys_setting reads per request.

packages/rest/src/rest-server.ts ~800 documents this whole block as "~16 sequential queries" and memoizes it per request (execCtxMemo) — but nothing caches it ACROSS requests, so every request pays it once.

D. Route handler (5–6 more):

• enforceApiAccess → loadObjectItems → getMetaItems('object') ALWAYS queries sys_metadata (1–2: the empty result triggers the alt-type retry) — packages/metadata-protocol/src/protocol.ts ~5700;
• plugin-security's engine middleware runs resolvePermissionSetsForContext → dbLoader (sys_permission_set {name $in}) with no cache, and it runs TWICE — once for the find, once for the COUNT (security-plugin.ts ~1351);
• the data SELECT itself;
• findData runs engine.count() whenever a limit is present (protocol.ts ~8858) — a second data query even for $top=1.

E. Zero-hint observation: the SqlDriver's tenancy auto-scoping itself issues no extra queries — but its INPUTS (accessible_org_ids, org_user_ids) are what B pays for, including the limit-1000 fellow-org read.

Consequences on a real deployment (cloud prod/staging)

• ~1.5s fixed server time per authenticated data request at ZERO concurrency (prod; ~6s staging where per-query RTT is ~300ms).
• Requests being ~100% DB-bound makes the pg pool cap the request-concurrency cap: cloud measured a hard knee exactly past 10 concurrent (= its pool max), median doubling at 20. The Console home fires 27 API calls in one cold load.

Fix directions (each independently valuable, roughly by leverage)

⚠️ This list predates #11633's five legs landing. Re-derive which entries survive before acting on any of them.

1. Session caching: enable better-auth cookieCache (signed cookie, short TTL) or an in-process TTL cache keyed by session token — removes A entirely on warm requests.
2. customSession is redundant work on the data path: B re-derives everything A3–A5 derive, more completely. Consider gating the customSession enrichment to the endpoints that need it, or a short per-user TTL cache.
3. Cross-request TTL cache for resolveUserAuthzGrants keyed (userId, tenantId) with write-invalidation or a short TTL. ⚠️ This is authz caching leg B: grants cache — coarse invalidation, default TTL=0 (off), expiry-boundary expiry, bypass list #11971's face and it has LANDED — do not rebuild it; measure it.
4. Batch B's reads: steps 6–13 are ~8 sequential round trips that could be 2–3 batched/joined queries; the duplicates (A2/13, A3/9) are free wins.
5. Cache successful localization reads with write-invalidation (the 新环境日志被 sys_setting 'no such table' ERROR 刷屏：本地化读取先于建表，真错误被噪音淹没 #10221 cache deliberately holds failures only; the dogfood analytics-timezone test pins read-after-write — invalidation-on-write satisfies it).
6. Cache getMetaItems' sys_metadata read (short TTL / registry-epoch key), and skip the alt-type retry when the first read returned an empty-but-healthy result set.
7. Reuse the find's permission-set resolution for its count (same request, same context — the middleware resolves twice today).
8. $count=false fast path: honor the existing $count parameter to skip the COUNT for callers that don't need total (objectui's cold-load probes mostly don't).

Per-query evidence is directly obtainable on any deployment of current main by an admin: X-OS-Debug-Timing: json returns Server-Timing (db;dur=…;desc="N queries") plus X-OS-Debug-Timing-Detail (slowest parametrized statements) — rest-server.ts:1937 opens the disclosure gate for admin principals.

Generated by Claude Code