perf(runtime): investigate synchronized workspace latency step after 20:00Z

[tiankaima]

Incident summary

Two independent bearer-authenticated workspace routes developed the same persistent latency step at approximately 2026-07-28 20:00Z, 11.5 hours after v1.77.21 reached 100% production. All responses remained 200 and Workers reported no runtime errors, exceeded-resource events, or memory events.

This timing does not support labeling the incident a #670 deployment regression or a Prisma-client regression.

Production evidence

Equal six-hour windows, exactly 72 calls per endpoint in each window:

Route	Metric	14:00–20:00Z	20:00–02:00Z
/api/workspace/homeworks	observed I/O avg / p50 / p95	112 / 104 / 160 ms	3101 / 3245 / 3581 ms
	sampled CPU avg	141 ms	297 ms (+110%)
	Workers wall avg	249 ms	3097 ms (+1144%)
/api/workspace/subscriptions/current	observed I/O avg / p50 / p95	88 / 82 / 125 ms	2271 / 2488 / 2798 ms
	sampled CPU avg	92 ms	286 ms (+210%)
	Workers wall avg	189 ms	2298 ms (+1115%)

Both routes remained slow through the latest complete window ending 2026-07-29 06:15Z. The section-detail CPU distribution decreased across the same boundary, so catalog concurrency is not a sufficient explanation.

The scheduled Static Sync ran 19:21:25–19:24:54Z. It completed successfully and did not overlap the 20:00Z boundary; the temporal proximity is worth testing at the next run but is not causal evidence.

Likely layers to distinguish

• Hyperdrive connection acquisition / placement change;
• database execution/lock/cache state or account-specific row shape;
• request-scoped pg pool connection churn;
• auth/token lookup versus application data queries;
• scheduled production maintenance effects.

Related: #45 in Life-USTC/Bot will consolidate periodic reads and reduce aggregate load, but that change must not be treated as resolving this per-call latency incident. #603 owns the production Hyperdrive role/cache architecture; #530 owns Worker route CPU attribution.

Acceptance criteria

• Capture a trace or equivalent timing split for auth, pool/connect, and each database read without logging credentials or row data.
• Compare at least one slow production-equivalent request with a fast request using the same route/account shape.
• Record Hyperdrive placement/config/version and database health/locks around a subsequent scheduled sync boundary.
• Determine whether the latency follows route, user/account data volume, colo/placement, connection creation, or database query execution.
• Add only the instrumentation needed to close the attribution gap; successful high-frequency logs must remain sampled.
• Implement a demonstrated fix with a focused load/shape regression test.
• Verify both routes over a complete post-deploy window with p50/p95/p99 and error/resource-limit rates.
• Keep the production role/cache safety work in security(db): replace production Hyperdrive postgres origin with cache-disabled RLS runtime role #603; do not enable caching for auth, permission, or user-fresh reads as a latency workaround.

[tiankaima]

PR #674 adds empty-attribute trace spans for auth and each major read stage on both affected routes. It also overlaps the independent viewer and subscribed-section lookups in /api/workspace/homeworks. This is intentionally instrumentation plus one demonstrated safe wall-time reduction, not a claim that the synchronized production step is already attributed. Keep #672 open until post-deploy traces distinguish auth/read/connection/DB layers and a complete comparison window is available.

[tiankaima]

v1.77.22 is now at 100% production and the new empty-attribute workspace spans are live. The initial post-deploy Worker window showed 0 runtime/resource/application errors, but it does not yet contain enough affected workspace samples to attribute the synchronized latency step or compare p50/p95/p99. Keeping #672 open for a complete trace window; no caching or Prisma cross-request reuse workaround was introduced.

[tiankaima]

Final initial window 07:56–08:06Z contains only 2 calls per affected workspace route. Observed I/O averages were about 139.5ms (homeworks) and 137.5ms (subscriptions/current), with 0 Worker/runtime/application errors. This is directionally much better than the prior multi-second step but far below the sample size needed for attribution or p50/p95/p99 closure. Keep #672 open for at least 6–12h (24h preferred), including the next historical boundary; the new auth/read spans are live for that comparison.

[tiankaima]

v1.77.22 complete 6-hour follow-up (2026-07-29 08:00–14:00Z):

• /api/workspace/homeworks: 72 calls; observed I/O p50/p95/p99 109/182/199 ms. One isolated 5,986 ms tail occurred at 12:16:30Z.
• /api/workspace/subscriptions/current: 72 calls; p50/p95/p99 85/118/150 ms; max 177 ms in this window.
• All responses were 200 and the prior synchronized multi-second distribution was absent.
• The 12:16 homeworks tail had a same-cycle subscriptions call of 118 ms. A later 15:06 subscriptions tail of 3,676 ms had a same-cycle homeworks call of 122 ms. These independent tails argue against one shared route-independent stall.
• Static Sync ran 14:07:32–14:10:27Z; surrounding 5-minute calls remained roughly 97–183 ms. Auth cleanup around 14:33Z likewise did not reproduce the step.

This falsifies the scheduled-sync and globally synchronized Prisma/DB-stall hypotheses for this window, but it does not yet attribute the isolated tails to auth, connect, or individual reads. Keep #672 open through the next historical 20:00Z boundary and a representative trace sample. Do not revive cross-request Prisma client reuse or use authenticated Hyperdrive caching as a workaround.

[tiankaima]

20:00Z boundary follow-up (current replacement route)

Traffic migration:

• /api/workspace/homeworks and /api/workspace/subscriptions/current stopped after 16:51Z.
• The periodic caller switched to /api/workspace/overview at 16:52Z, so this is now the route that can validate the historical boundary.

Four cycles corresponding to the 19:55/20:00/20:05/20:10 schedule:

• 19:57:40Z: 121ms, 200 bearer
• 20:02:40Z: 105ms, 200 bearer
• 20:07:40Z: 144ms, 200 bearer
• 20:12:40Z: 198ms, 200 bearer

There is no synchronized latency step at the historical boundary. A sampled 19:57 provider trace on Worker version 87477425 had root 124ms, CPU 105ms, wall 222ms, app resolve 120ms, and three Hyperdrive connect spans at 0ms; outcome was ok. The earlier overview tails at 18:47/18:52/18:57Z were 6.602/5.394/6.225s and then recovered, but none of those requests entered the 5% provider trace sample, so their exact slow stage remains un-attributed.

A deterministic amplifier is now established in getCompactOverview:

• user fields and active section IDs perform two User.findUnique reads;
• three Todo branches open independent RLS transactions; listTodoSummary alone performs set_config plus three serial counts and one list;
• phase two starts seven DB reads under a request pool capped at three;
• item state adds one grouped comment read.

This is about 19 application queries plus transaction setup per overview call. It can amplify a database tail into multiple pool waves, but the unsampled slow requests do not justify claiming it as the original trigger.

Next implementation under this existing issue:

1. add fixed, empty-attribute overview auth/read and low-cardinality read-subphase timing;
2. combine the user and active-section read;
3. consolidate the three Todo RLS contexts into one specialized overview transaction, preserving the response and RLS boundary;
4. compare the same account shape after deployment before selecting any further query rewrite.

No authenticated cache or cross-request Prisma reuse will be introduced. #672 remains open for the post-change complete comparison window.

[tiankaima]

Implementation trade-off correction

A single outer interactive RLS transaction would save two transaction setups, but Prisma would execute the six Todo SQL statements on one connection. That changes the current three-branch parallelism into serialization and can raise normal p50. The fast production trace showed three Hyperdrive connect spans at 0ms, so there is not enough evidence that connection acquisition dominates.

The implementation therefore keeps the three Todo reads parallel and records them separately as fixed, full-sample stages:

• todo_summary
• due_todo_count
• due_todo_sample

The safe deterministic fix remains: merge the duplicate user/profile and active-section User.findUnique calls. Additional fixed stages cover user_sections, counts, lists, and item_state, plus empty-attribute workspace.overview.auth/read spans. No outer RLS serialization, cache, endpoint, or response change is included.

Production stage data will decide whether a later specialized aggregate query can reduce SQL count without sacrificing parallelism.