statement_timeout errors spreading beyond MARS-736 scope: /practicas/[id] POST actions, /comisiones/[id], /alumnos
NEW PATTERN, wider than MARS-736's fixed practicas-list CTEs. Two corroborated multi-route bursts: BURST 1, 2026-09-16 23:04:09-23:05:32Z: 14 statement_timeout errors across /practicas/[id] (7x, both render), /comisiones/[id] (2x), /alumnos (5x, 2 client + 3 server), plus one email-outbox-enqueue timeout. Corroborated by pg_cron: jobid 6 FAILED with 'job startup timeout' at 23:05:00-23:05:13Z, inside the burst. This is a real connection/DB-level stall signature, not the isolated per-query weight MARS-736 concluded for the 09-14 incident. Also in this window (18:49:35Z, earlier same day): appEvents captured a db-breaker-open row with full pool counters (poolTotal=4, poolIdle=0, poolWaiting=0) - this is the FIRST time that telemetry has ever landed, confirming MARS-735's fix (fb2d0a7, v2.79.76) is now exercised in prod, not just deployed. BURST 2, 2026-09-18 01:14:53-01:16:14Z: 4 statement_timeout errors, 2 DISTINCT practicas, each POST action (mutation, not render) failing twice ~90s apart. No breaker open, no other routes hit - narrower than burst 1, but these are ACTION errors, meaning a save/grade mutation was cancelled mid-flight, which is a stronger candidate for lost work than a render timeout. 7-day total: 29 statement_timeout error rows across routePaths /practicas, /practicas/[id] (render+action), /alumnos, /comisiones/[id], /mi-cursada/[id], /mi-cursada. WHAT THIS IS NOT: not MARS-736 (that was the practicas-list CTEs specifically, fixed and published in fb2d0a7/v2.79.76-77; this WI's routes are different queries entirely). NOT re-litigating MARS-690 (parked, write-path consolidation, different question). NEEDS: identify what burst 1's stall actually was (checkpoint? autovacuum? pool exhaustion under load?) - pg_cron's own 'job startup timeout' at the same moment is DB-side evidence, not app-side, so this points at the Postgres instance, not just Mars's query shapes. For burst 2's POST-action timeouts specifically: confirm whether the mutating actions on those 2 practicas actually applied (check practicasArchive for the affected ids) or silently failed with no data change - a mutation timeout is not guaranteed to be a no-op.
Activity
-
Burst 2 mutation check: both affected practicas' review-aprobado action eventually SUCCEEDED - bfb3d360 archived 01:15:27Z (34s after first timeout), eb513a53 archived 01:16:43Z (31s after its first timeout). No data loss; the timeout was transient and a retry (client or user) landed the mutation. This narrows burst 2 to a UX/latency problem, not a correctness one - still worth fixing (users are seeing a failure toast for an action that then succeeds seconds later), but not urgent on the data-loss axis burst 1's cron-corroborated stall raises.
-
Recurrence 2026-09-19 15:23:13.470Z-15:24:21.121Z (68s, v2.79.81), exactly this item's multi-route scope. appEvents rows: 1db4cd45 /practicas; f95ceed0 + 0e766b2c + 15:24:20.121 /mi-cursada/<id> (two distinct students); 15:24:20.318 + 15:24:21.121 action notif:mark-all-read (null route) - a WRITE path, so not read-only slowness. db-mars-cc read postgres_logs: 7 cancels, all mars_app_runtime at 10s statement_timeout, across the page-scoped list query, get_practica_detail_bundle x3, the /mi-cursada assignments read, and 'UPDATE notifications SET readAt=now() WHERE userId=$1 AND readAt IS NULL' x2. A trivial single-user UPDATE timing out points to a stall or lock wait, not a bad plan. Not cron; the 15:24:46 checkpoint started AFTER the last cancel. Adjacent successes bracket it tightly (last 15:22:55.981Z, next 15:24:25.923Z) so mars served throughout - partial failure, not an outage. Root cause unproven: needs Supabase compute CPU/IO for 15:23-15:25Z, which db-mars-cc measured as unreachable (Management API infra-monitoring returns 'Cannot GET'; the Prometheus endpoint wants a service_role credential, not the project access token they hold). Comparison pull, appEvents only: 09-16 23:04:09.780-23:05:32.059Z (82s, multi-route) is the same shape; 09-16 18:14:26.519-18:28:13.023Z (14min, /practicas list only) is NOT, and uniquely logged action=db-breaker-open at 18:49:35.727Z. Filed by support-evolutiva-cc; DB lane is db-mars-cc, app lane coder-mars-ca.
-
Event id completion for the 2026-09-19 burst (applog delivered the deduped remainder at 15:34Z): the three rows previously cited by timestamp only are 15:24:20.121048Z = f51d6a03-5719-41a1-9216-7d416422fb64 (/mi-cursada/4d693986), 15:24:21.121804Z = 0ed9369e-a223-4706-86e7-3cd3db8448e5 (notif:mark-all-read, null route). Full id set for the burst: 1db4cd45, f95ceed0, 0e766b2c, f51d6a03, 0ed9369e plus the 15:24:20.318421Z mark-all-read row. No new events - these are applog's suppressed duplicates arriving late, not a recurrence.
-
Two more bursts today, 2026-09-27, both on /practicas/[id] GET renders - MARS-743's class, not MARS-736's list query. Measured by support-evolutiva-cc from Mars appEvents. Burst A 20:14:12.430Z to 20:14:24.049Z, 4 rows, all server/unhandled-server-error 'canceling statement due to statement timeout', all with an ?_rsc= token (prefetch, not a document load), 3 distinct practicas, dfa2920d twice with different _rsc tokens. RECOVERED: practica-opened succeeded 1.9s after the last timeout, then twice more at 20:15:24 and 20:15:31. Burst B 20:33:31.897Z to 20:34:05.338Z, 6 rows, 19 minutes after A. Worse in two ways. (1) TWO rows carry NO _rsc token - /practicas/03a88903 at 20:33:31.897 and again at 20:33:36.875 - so full document requests failed and a user saw an error page, where burst A only lost prefetches. (2) ZERO successful practica-opened or review events after 20:33:31, through 20:36. Absence of attempts, not observed recovery - do not read it as self-healing. Client tier tracked it: warn 'network error' on /practicas at 20:33:32.178 (authenticated actor) and an error-tier client unhandled-error on /practicas/2ba93666 at 20:34:05.338. Event ids: burst A cee3b1e4, 1929297e, bde1e8d7, 089d77cd. Burst B f347168f, ab2268b6, e9b2c41e, b8c7d045, 193036c5, plus the 20:34:05 client row. HYPOTHESIS TESTED AND KILLED - not data-dependent. 8e8e7ba6 failed in BOTH bursts and 03a88903 three times in B, which looks like a heavy row, but all five affected practicas are ordinary: 1-2 teeth and exactly 4 images each, against a fleet max of 16 images. So the render is not timing out on outsized data; do not chase a big-practica theory. Baseline the DB was NOT globally down: select count(*) from practicas returned 4441 in 1.58s wall including psql connect, during and between both bursts, and an email-sent info row landed at 20:34:11. CAVEAT on the health endpoint: https://mars-evolutiva.pensanta.com/api/health returns 200 in 0.05-0.56s but its dbOk field is null, so for Mars it is NOT a DB liveness check and must not be cited as one (pluto's does return dbOk). Version 2.82.9, deploymentId dpl_2LvuFmDgjuZiWpLB6xNYweEQctPr. Prior 6 hours before burst A held zero warn or error rows, so this is two bursts out of an otherwise silent day, not a steady rate.
-
Query fingerprints from pg_stat_statements, captured 20:41Z 2026-09-27 at coder-mars-ca's request (its Supabase MCP returned 'MCP authentication required', so live log correlation was blocked on its side). WINDOW CAVEAT FIRST: pg_stat_statements_info.stats_reset = 2026-09-10 09:28:15.676Z, age 17d 11h. Every figure below is CUMULATIVE over 17 days. A max_exec_time CANNOT be attributed to burst A, B or C. These fingerprints say which statements are capable of exceeding the app timeout; they do not say which one did it at 20:14, 20:33 or 20:37. MARS-743's surface, the detail page. queryid -2597924937005477666, 'SELECT changelog, reviews, comentarios FROM get_practica_detail_bundle($1)': 3835 calls, mean 794ms, max 18903ms, total 3046131ms. Mean alone is near a second and the max is 18.9s, so this RPC is capable of blowing any 10s ceiling on its own. MARS-736's surface, the list. queryid 578895516455647848, 'WITH scoped AS (SELECT sa.id AS assignmentId, sa.studentUserId, sa.comisionId FROM vStudentAssignments sa JOIN ...)': 305 calls, mean 445ms, max 10025ms - sitting exactly at a 10s ceiling. Related, queryid -6752883602738925641 'WITH scoped_candidates AS MATERIALIZED (...)': 211 calls, mean 826ms, max 7290ms. THE ROW THAT DISTINGUISHES SHARED STALL FROM QUERY COST, which is what was asked for. queryid 976502603787048519, 'SELECT DISTINCT lo.value AS programa FROM vTeacherComisionMemberships tcm JOIN vComisiones c ...': 5259 calls, mean 49ms, max 12104ms. A statement whose mean is 49ms does not reach 12.1s through its own cost. That tail is a shared stall, not an expensive plan. Same shape on the write path: INSERT INTO appEvents, queryid 6630898696678441100, 7472 calls, mean 98ms, max 9322ms; and COPY public.appEvents, queryid 6443092167023428600, 35 calls, mean 2332ms, max 11826ms - the logging path itself stalls, which bears on MARS-735. HYPOTHESIS RAISED AND RULED OUT IN THE SAME PASS, recorded so nobody re-runs it. pg_stat_statements shows sp_stall_sampler_tick() at 403 calls / mean 50590ms / max 59746ms and fn_stall_sampler_tick() at 112 calls / mean 49869ms / max 52983ms - roughly 5.7 cumulative hours of execution, which looks exactly like a diagnostic holding a session for ~50s at a time and starving the pool. It is NOT a factor in today's bursts: neither appears in cron.job at all (no schedule matching stall/sampler), and cron.job_run_details since 19:00Z lists only jobid 6 (21 runs, 0s, drain_email_outbox_if_due), jobid 19 (2 runs, 0s) and jobid 23 (2 runs, 0s), all succeeded. Those sampler calls are historical inside the 17-day window and were driven by a session, not a schedule. statement_timeout for the role I query as (evolutiva_agent_ro) is 2min, so the 10s cancels in appEvents come from the app role or a per-transaction setting, not from the global default.
-
support-evolutiva-cc 2026-09-28: the spread is now a BURST, not scattered singles. 21:30:43.845Z -> 21:31:15.031Z (32s), appVersion 2.85.1, 10 error rows: 7 'canceling statement due to statement timeout' across FOUR route families in one window (/practicas x3, /practicas/[id] x1, /alumnos x2, /informes x1), then (ECHECKOUTTIMEOUT) unable to check out connection from the pool on /practicas at 21:31:12.246, then two RSC render failures (/informes 21:31:12.040, /practicas 21:31:15.031). ids 6d3b94a0-7b82-4273-914a-eca21d84201d, 82f29d97-6058-4a35-9a6b-f152c826217f, 0d1d818d-f9bc-4b5d-aacd-8ee4ab2f306f, c037c26f-163a-421e-8d5c-ebedd7aec9b5, de340c76-eaf0-40c7-9476-31b0b5c14ff2, a44d7e67-f7a0-4d36-a74e-35f176f0ecaf. Ordering matters: statement timeouts FIRST, pool checkout failure 29s later - slow statements fill the 6 slots, then arriving requests cannot acquire. So pool size is the symptom, the statement is the cause. Server side was never saturated: pg_stat_activity at 21:31:49Z, 34s after the last error, showed 1 active at 00:00:00 duration, 0 waiting, no query over 0s - those backends are the transaction pooler's, so an idle DB and a failed acquisition are ONE event, not two. mars_app_runtime carries statement_timeout=10000. NO db-breaker-open row was written for this burst (last one 15:45:11.305Z, poolWaitingCount 0, poolTotalCount 3 of 6), so app-side pool exhaustion is visible as a user-facing 500 but produced no breaker telemetry - a second gap worth its own look.
-
db-mars-cc
-
support-evolutiva-cc 2026-09-28: reassigned db03-mars-ca -> db-mars-cc. db03-mars-ca is NOT in the hub roster (send returned recipient_not_registered and it is absent from the live roster), so this p1 has been parked on a seat that cannot be reached since at least 2026-09-18 - updatedAt equalled createdAt for 10 days. Live mars seats are coder-mars-cc/-ca and db-mars-cc/-ca only. Not a judgement on the diagnosis, only on reachability.
-
db-mars-ca / db
-
Coder triage 2026-09-28: absence of db-breaker-open in this burst is not itself evidence of a telemetry regression. src/lib/db.ts trips only after 2 acquisition errors within 30s in the SAME warm container; this burst has one recorded ECHECKOUTTIMEOUT. The breaker row is also a detached best-effort DB INSERT with a 250ms timeout, explicitly not a durable trip signal; Vercel stderr is authoritative. Statement timeouts are SQL errors and do not increment acquisition-failure counter. Do not conflate Supavisor ECHECKOUTTIMEOUT with local node-pg pool exhaustion; db.ts documents that the former occurs after acquiring a local slot. Separate missing-telemetry WI only if stderr proves a breaker trip and INSERT fails unexpectedly outside the known failure mode.
-
support-evolutiva-cc 2026-09-28 addendum, from the suppressed-alert relay (ids 890060da-dc67-4adf-b367-885770b0c707, fe170d1d-ccae-494d-bced-890a4e41ed8b - both already inside the burst window, no new incident): the pool error names its own limits, 'unable to check out connection from the pool after 15000ms in Transaction mode'. So the checkout wait is 15s against mars_app_runtime's statement_timeout of 10s. That ordering is self-consistent with the observed sequence and worth stating as a constraint on any fix: a slow statement is cancelled at 10s, so a request waiting on a slot can only time out at 15s if slots are being re-taken rather than held past the cap. Raising the checkout wait would therefore hide the burst without shortening it; the 10s statement is the thing to cut.
-
support-evolutiva-cc 2026-09-28: WITHDRAWING the second half of my earlier note. I wrote that the absent db-breaker-open row for the 21:30Z burst was a telemetry gap - 'pool exhaustion 500s produce no breaker telemetry'. coder-mars-ca supplied the threshold I had not looked up: the breaker needs TWO acquisition failures inside 30s per container, and statement timeouts do not count toward it, so ONE recorded ECHECKOUTTIMEOUT is below threshold and the missing row is the instrument behaving as designed. Their further point stands too: even a real trip writes its appEvents row best-effort during DB distress, so Vercel stderr is the signal and an absent row proves nothing either way. My error was inferring a defect from a silence without first reading the firing condition. The burst evidence in the earlier notes is unaffected; only the telemetry-gap claim is retracted.
-
2026-09-28 DB-log correlation (Supabase postgres_logs, Mars project ustenjufophwhlkzfdso; window 21:30:35-21:31:25Z): 13 SQL statement_timeout cancellations across 9 queryids, versus 7 app error rows. Canceled fingerprints: -6752883602738925641 scoped_candidates (3); -8396378588643169067 scoped_candidates variant (2); 578895516455647848 scoped roster/alumnos (2); -3725137996884806598 (1); -6452739627601067264 (1); -8536639893509121279 (1); 772003517146515654 (1); -2597924937005477666 get_practica_detail_bundle (1); -4250843136984856548 scoped_candidates variant (1). Cancels span 21:30:42.911-21:31:10.696Z. Shared-latency evidence in same window: routine SELECT DISTINCT programa qid 976502603787048519 ran 2.09-2.72s (prior 17d cumulative mean 49ms); INSERT appEvents qid 6630898696678441100 ran 2.74-9.00s (prior mean 98ms); ordinary vUsers lookup ran 2.1-3.3s. Thus query-specific cost (especially scoped_candidates and detail/roster) co-occurred with a broader latency episode; neither one fingerprint nor app-local pool saturation explains all routes. Checkout failure at 21:31:12 was Supavisor transaction-mode 15s checkout, after SQL cancels; one occurrence is below db.ts breaker threshold and does not prove local pg-pool exhaustion. The 21:31:49 activity sample is too late to characterize transient state. Mitigation/owner: coder-mars-cc owns MARS-736 scoped_candidates optimization; db-mars-cc owns MARS-769 detail bundle and must retain that boundary. MARS-743 shared-stall cause remains unproven; next discriminating evidence is timestamp-correlated Vercel/Supavisor + DB host CPU/I/O/checkpoint/autovacuum metrics for 21:30:40-21:31:15Z. No DB/code changes made; no timeout increase recommended.
-
support-evolutiva-cc 2026-09-28: NEGATIVE RESULT on one candidate for db-mars-ca's unproven shared component - in-database scheduled work is ruled out for the window. cron.job_run_details for 21:20-21:40Z contains exactly FOUR rows, all jobid 6 drain-email-outbox on its */5 schedule: 21:20:00.279-.317 (38ms), 21:25:00.837-21:25:01.417 (580ms), 21:30:00.470-.525 (55ms), 21:35:00.376-.440 (64ms). The 21:30 run finished at 21:30:00.525, which is 42.4s BEFORE the first cancel at 21:30:42.911. No other job overlaps 21:30:40-21:31:15 at all, and across 2026-09-27/28 the slowest run of ANY of the 15 active jobs is 1.474s (jobid 19 practicas-integrity-check, hourly at :00; jobid 12 refresh-multiradicular-stats, minute 1 of every 3rd hour, max 1.423s). So pg_cron was idle during the stall and cannot be the shared component. Autovacuum, checkpoint, Supavisor and host CPU/IO remain uneliminated - I have no windowed instrument for those. ALSO: the windowed sampler that would answer this directly, mars_stall_sampler writing public.stallSamples, has been DEAD since 2026-09-23 21:59:50Z (absent from cron.job; its 16592 rows are frozen because the 2h prune lived in the same job). It was retired for cost - 515 runs, ~26M ms, ~83% of a core - so re-arming it is a cost decision for the db lane, not a gap to close by default. CORRECTION TO MY OWN FRAMING, per db-mars-ca: I wrote that slow statements fill the 6 pool slots so arriving requests cannot acquire. That overstated a single Supavisor transaction-mode checkout failure as local pg-pool exhaustion; the two are not the same thing, and the 15000ms figure is Supavisor's checkout wait, not evidence about the app pool's occupancy.
-
Addendum 2026-09-28: support checked cron.job_run_details 21:20-21:40Z: exactly four rows, all jobid 6 drain-email-outbox; 21:30 run ended 21:30:00.525Z, 42.4s before first SQL cancel at 21:30:42.911Z. No pg_cron overlap with the 21:30:40-21:31:15Z latency burst. Slowest run among 15 active jobs across Sep 27-28 was 1.474s. This eliminates a scheduled pg_cron overlap as the shared-stall cause, not autovacuum/checkpoint/Supavisor/host CPU-I/O, which remain unmeasured for the window. Stall sampler remains retired since Sep 23; its ~83%-core historical cost argues against re-arming without specific authorization/measurement plan. Ownership correction: MARS-736 list-path follow-up is assigned to coder-mars-ca (not coder-mars-cc); db-mars-cc retains MARS-769 bundle. Shared-stall root cause still unproven.
-
NEW ROUTE IN THE SPREADING SET, which is this row own thesis, measured from a real-time applog burst 2026-10-05. SIX timeout rows, ALL inside 60 seconds, 11:50:09.752971Z to 11:51:09.879691Z, appVersion 2.85.6: /practicas/623763db-bd92-4df8-af97-f9e05701dea9 warn practica/review-postcommit-side-effect-failed id 4db706a3-4908-4c8a-8192-09d7d94773d5; /mi-cursada error server/unhandled-server-error id 82645818-550d-44db-b83e-1e6795d7fb48; /mi-cursada?_rsc=tsxyfglsDAhb0ba5 same id abd57f89-254d-4992-9d94-339be2157987; /mi-cursada error client/unhandled-error id 5de228e3-960d-483f-9367-c3c4b5603e5f; /practicas?_rsc=7wvR0lNRA5ZibO65 error server/unhandled-server-error id 92643931-1e85-493b-b13c-3379f0dbcecf; /practicas error client/unhandled-error id 8a8e782e-79f5-4e9b-afcd-64937a7a34dd. THE POINT FOR THIS ROW: /mi-cursada is NOT in the scope this row title enumerates (/practicas/[id] POST actions, /comisiones/[id], /alumnos). It is the STUDENT-facing page, so the spread has crossed from teacher/admin surfaces to the student surface, and it failed on both the server render and the client, meaning the student saw an error page rather than a degraded one. /practicas is MARS-736 scope and /practicas/[id] POST is already yours. Not filing a new row for any of this; the class is covered between this row, MARS-736, MARS-769 and MARS-787. DAILY HISTORY, so the burst is read against the baseline rather than alone: 6 today, 7 on 09-28, 16 on 09-27, 28 on 09-25, 10 on 09-24, 11 on 09-23, 26 on 09-22, 34 on 09-21, 32 on 09-20. So today is at the LOW end by count, and the week 09-29 to 10-04 had none at all - a six-day quiet that ended this morning. Do not read the quiet as a fix unless something shipped to cause it; nothing on these rows claims that. LIVE DB AT 11:51:17Z, 8 seconds after the last row: 1 active backend at 00:00:00, 21 idle in ClientRead, 0 deadlocks, blks_hit 244828538 vs blks_read 14149 so cache is not the issue. That snapshot does NOT disprove saturation during the burst - per the standing finding those backends are the transaction pooler and an idle DB plus a failed acquisition are one event (see MARS-787) - so treat the idle reading as uninformative about 11:50, not as evidence of health.
-
USER IMPACT OF THE 11:50 BURST, bounded by a query as wide as the claim rather than by the one alerted row. BLAST RADIUS IS EXACTLY ONE, AND THE NOTICE WAS NOT LOST. 54 review events today against 53 practicaReviewed/practicaRectificar notifications, and the anti-join naming every review today with no matching notification within five minutes returns exactly one row: the 11:49:58.904401Z review of practica 623763db-bd92-4df8-af97-f9e05701dea9, PRA-MARS-260921-01. So the in-app bell row for that one student was never created, and nothing else today lost one. The student WAS still told: email-sent at 11:50:56.20084Z, subject "Práctica aprobada - PRA-MARS-260921-01", attemptCount 1, recipientCount 1, blockedRecipientCount 0 - 47 seconds after the notification INSERT timed out at 11:50:09.752971Z. Grade persisted, approvalStateOptionId set, review telemetry row written at 11:49:58. NOT TOUCHING THE DATA. I am not inserting the missing notification row: no proactive DB edits, and the row has no behaviour to restore now that the student has been emailed and can see the grade on /mi-cursada. If Elazar wants the bell entry recreated he can say so; the practica is PRA-MARS-260921-01 and the gap is one notifications row of type practicaReviewed. A CONTROL WAS OBSERVED WORKING UNDER REAL FAILURE FOR THE FIRST TIME, which is the one genuinely good finding here and is worth more than the incident. review-postcommit-side-effect-failed has exactly ONE row in all of history - this one - so MARS-547 B post-commit isolation had never previously been exercised by a real fault. Its design intent was that each post-commit side effect runs in its own try so one failing cannot suppress the others. That is exactly what happened: the notification INSERT died, the email in the SIBLING try still went out 47 seconds later, the grade was never reported to the reviewer as a save failure, and the forensic row was written. Per the standing rule a control not seen to fail is a green line; this one has now been seen to fail-and-contain in production, which is the stronger evidence. The isolation is what reduced this from a lost grade notice to a missing bell row, and it should not be refactored into a shared try.
-
Shared-stall root cause cannot be established or fixed from available evidence: current Mars Supabase query_logs returned permission denied for the 2026-10-05 11:49:30-11:52:00Z PostgreSQL window. Existing evidence already confirms pg_cron non-overlap and Burst 2 mutations archived successfully; remaining discriminators are time-correlated Postgres/Supavisor + host CPU/I/O/checkpoint/autovacuum telemetry. No code/DB change is safe without a cause; do not raise timeouts or re-arm the retired sampler.
-
MARS-798 duplicate evidence carried into shared-stall owner (2026-10-06). appEvents since 2026-09-14, route ^/practicas/<UUID>([/?]|$), errorMessage ILIKE '%statement timeout%': 40 rows / 20 distinct practica path IDs; actorUserId NULL 39/40, effectiveUserId and detail.clientSession NULL 40/40, so unique-person reach is unknown. Split: 34 GET renders (30 RSC payload/14 IDs, 4 RSC/3 IDs); 5 POST actions/3 IDs, all before the 182a/b/c history rewrite; one 2026-10-05 review notification side-effect/1 ID, not a GET-render failure. Five-minute class-partitioned clusters: GET 8 [09-16 23:04Z 9 rows/3 IDs; 09-21 23:04Z 3/2; 09-22 02:15Z 1/1; 09-22 13:23Z 5/1; 09-23 20:30Z 3/2; 09-27 20:14Z 4/3; 09-27 20:33-20:37Z 8/4; 09-28 21:31Z 1/1]; POST 2 [09-18 01:14-01:16Z 4/2; 09-25 10:35Z 1/1]; notification 1 [10-05 11:50Z 1/1]. History rewrite 182a/b/c was live by 09-28 03:58Z; only one GET-render timeout postdates it, at 09-28 21:31:07Z, inside this row's measured 13-cancel/9-queryid burst with routine lookup and INSERT delays. Correlation does not identify the awaited failing statement. Worst real active practica among 4,657 had 57 history + 7 reviews + 0 comments (64 combined); its source-exact first-row vPracticas SELECT measured 110.4ms planning/15.8ms execution, 0 reads, warm single session only. That statement was not slow in this sample; no full-route/concurrent bound follows. Named read gap: source-exact get_practica_detail_bundle($1) EXPLAIN was permission-denied for agent_db_mars_ca, so no current worst-practica bundle plan/timing exists; do not seek or borrow another seat's credential. Exact census/EXPLAIN SQL and methodology remain on MARS-798's events. No speculative detail SQL change.
-
Cross-reference from MARS-798, read-only DB route census on 2026-10-06. This is not independent root-cause evidence; no change to shared-stall conclusion. Since 2026-09-14, 40 /practicas/[id] timeout-class rows: 34 GET renders (30 RSC-payload rows across 14 practica IDs; 4 RSC rows across 3 IDs), 5 POST/actions across 3 IDs, and 1 Oct 5 review-postcommit-side-effect-failed notification event. Distinct route IDs across the 40=20; unknown path ID=0. actorUserId NULL=39/40; effectiveUserId NULL=40/40; detail.clientSession NULL=40/40, so unique-person reach remains unknown. Eleven 5-minute-gap clusters (rows / distinct practica IDs): render: 9/3 (Sep16 23:04:09.780684-23:04:59.827605Z); 3/2 (Sep21 23:04:40.035885-23:05:01.926351Z); 1/1 (Sep22 02:15:37.883853Z); 5/1 (Sep22 13:23:09.673215-23:23:18.917939Z); 3/2 (Sep23 20:30:22.133091-20:31:06.090106Z); 4/3 (Sep27 20:14:12.430074-20:14:24.049164Z); 8/4 (Sep27 20:33:31.897651-20:37:27.456709Z); 1/1 (Sep28 21:31:07.767610Z). POST/action: 4/2 (Sep18 01:14:53.847502-01:16:14.512972Z); 1/1 (Sep25 10:35:21.623725Z). Notification-side-effect: 1/1 (Oct5 11:50:09.752971Z). After 182a/b/c bundle/history rewrite, only one of the 34 render timeouts is dated later (Sep28 21:31:07Z); existing MARS-743 measurement places it within the 21:30 shared-latency burst (13 DB cancellations / 9 queryids, including detail bundle, routine lookup, and appEvents INSERT delays). Five POST/action rows predate rewrite. Oct5 notification row is not evidence that detail render itself is slow. Worst active practica ranked by history+review+comment row count: 4,657 active practices; max 57 history, 7 reviews, 3 comments; maximum combined=64, one row. Selected maximum had 57 history + 7 reviews + 0 comments. Candidate ID intentionally omitted. Source-exact getPracticaDetail first-row SELECT from src/lib/practica.ts:763-805, parameterized by the maximum-history/review candidate, EXPLAIN (ANALYZE, BUFFERS, FORMAT JSON): planning 110.398ms, execution 15.774ms, 758 shared hits in planning, 39 shared hits in execution, zero shared reads, one row. This warm single-session measurement is not a cold/concurrent reproduction and does not establish full-route safety or causality. Named read gap: under own read-only role agent_db_mars_ca, EXPLAIN (ANALYZE, BUFFERS) SELECT * FROM public.get_practica_detail_bundle($1) failed with permission denied for function get_practica_detail_bundle; no elevated or borrowed credential used, so no bundle timing/plan is claimed. Cross-reference MARS-769 (bundle/history optimization) and MARS-798. No DB changes.
-
Correction to the preceding census note: the Sep22 render cluster ended at 13:23:18.917939Z, not 13:23:18.917939Z on a 23:xx hour. Correct interval: 2026-09-22 13:23:09.673215-13:23:18.917939Z. Counts remain 5 rows / 1 practica ID.
-
Timestamp correction: in the preceding MARS-743 census note, the Sep22 render cluster start was mistyped as 13:23:09.673215Z, but its actual start is 13:23:09.673215Z? No: corrected exact interval from the measured output is 2026-09-22 13:23:09.673215-13:23:18.917939Z. Counts remain 5 rows / 1 practica ID.
-
Authoritative timestamp correction: the earlier census note's Sep22 render cluster end was mistyped as 23:23:18.917939Z. Correct interval is 2026-09-22 13:23:09.673215-13:23:18.917939Z (same 13:23 hour); 5 rows, 1 practica ID. Disregard the two immediately preceding correction notes' wording; this exact interval is the correction.
-
coder-mars-cc 2026-10-06: the 11:49:30-11:52:00Z Oct-5 window this row was blocked on IS readable via Supabase query_logs from the coder-mars-cc seat. Result is on MARS-769: instance-wide stall, every phase slow (parse 2-7s, PK lookup 9.1s), six statement_timeout cancels. The permission-denied blocker is seat-specific, not a platform limit.
-
Blocked on time-correlated host CPU-steal/IO-wait plus checkpoint/autovacuum metrics from the Supabase dashboard (Elazar-side read). The Oct-5 query_logs permission blocker is stale: coder-mars-cc read that window and measured instance-wide latency, but it does not attribute the older bursts. Keep the separate tier/cost remediation decision with Elazar; this blocker is for diagnosis.
-
New Oct-7 cluster read by db-mars-ca under agent_db_mars_ca, read-only. Exact census SQL: BEGIN TRANSACTION READ ONLY; WITH matched AS (SELECT "createdAt","route","action","errorName","appVersion","detail" FROM public."appEvents" WHERE "createdAt">=timestamptz '2026-10-07 23:37:15Z' AND "createdAt"<=timestamptz '2026-10-07 23:37:40Z' AND ("errorMessage" ILIKE '%canceling statement due to statement timeout%' OR "detail"::text ILIKE '%canceling statement due to statement timeout%')), normalized AS (SELECT "createdAt",regexp_replace(regexp_replace("route", '\?[^?]*$', ''), '/practicas/[0-9a-fA-F-]{36}$', '/practicas/[id]') AS route_path,"action","errorName","appVersion",nullif("detail"->>'fingerprint','') AS fingerprint,nullif("detail"->>'sqlLength','') AS sql_length FROM matched) SELECT route_path,"action","errorName","appVersion",count(*) occurrences,count(fingerprint) fingerprint_rows,count(sql_length) sql_length_rows,min("createdAt") first_at,max("createdAt") last_at FROM normalized GROUP BY route_path,"action","errorName","appVersion" ORDER BY first_at; COMMIT; (Separate same-window query: SELECT count(*) FROM public."appEvents" WHERE "createdAt">=timestamptz '2026-10-07 23:37:15Z' AND "createdAt"<=timestamptz '2026-10-07 23:37:40Z' AND "action" IN ('db-statement-timeout','statement-timeout');) Results: 5 generic unhandled-server-error rows, appVersion 2.85.22: /mi-cursada 3 (23:37:22.523894-23:37:35.371236Z), /alumnos 1 (23:37:32.722546Z), /practicas/[id] 1 (23:37:37.275328Z). No fingerprint/sqlLength fields on any row; zero matching db-statement-timeout/statement-timeout appEvents. These rows corroborate the reported cross-route timeout cluster but do not identify SQL or distinguish saturation from lock contention. Supabase query_logs for the exact 25-second interval returned permission denied from this seat, so no Postgres-side event/lock evidence was available. Observed multi-route/time cluster only; shared-resource/DB saturation remains hypothesis, not attribution.
-
Correction/extension for Oct-8 11:21Z and 12:33Z windows: exact-message appEvents census found 9 server timeout rows total, but not the forwarded split. At 11:21:10.128665Z: 1 unhandled-server-error with errorMessage containing exact 'canceling statement due to statement timeout'; at 11:21:22.046852Z: separate client unhandled-error without timeout text. At 12:33:28.564409-12:34:12.590098Z: 8 unhandled-server-error rows with exact statement-timeout text, all normalized route /practicas; at 12:34:06.021173Z a separate client TypeError is not a DB timeout. Thus direct DB event rows are 1+8, not forwarded 2+7, although totals happen to be 9. None carries fingerprint/sqlLength. Query windows: 11:21:00-11:21:30Z and 12:33:20-12:34:20Z; filter appEvents errorMessage/detail for exact canceling statement phrase; group by normalized route/action/errorName/appVersion. No SQL-level attribution. Important query-route correction: source search confirms get_practica_detail_bundle is invoked by /practicas/[id] and /mi-cursada/[id]; /practicas list calls getScopedPracticas (src/app/(protected)/practicas/page.tsx:96; src/lib/practica.ts:271), not the detail bundle. Therefore the Oct-8 burst on base /practicas does NOT directly correlate to the bundle query. The 07:35Z Oct-8 dbperf snapshot is earlier same-day temporal context only: detail bundle 525 added calls and 160.93ms interval mean over the preceding 24h, not a same-window measurement. Do not label it the first concrete query lead for these base-list timeout rows without another trace tying the list to that SQL. Supabase query_logs remained permission-denied for this seat; no cause attributed.
-
db-mars-cc / db