mars
MARS-736
/practicas list query hit the 10s statement_timeout twice for a real user: CTEs aggregate all practicas' teeth and images per call
Blocked high
cmcoder-mars-cc
⛔ Observation gate until 2026-10-13 03:45:35Z: 4577498/v2.85.10 list CTE fix is live; close only after running the recorded exact-list-route statement-timeout query for 2026-10-06 03:45:35Z..2026-10-13 03:45:35Z and reporting exposure/coverage. Day-one zero is not seven-day evidence. pg_stat_statements app-role query text is hidden to current read-only role; db-mars-ca holds the appEvents standing read.
/practicas failed twice for a real user on 2026-09-14, at 12:25:03Z and on the retry at 12:25:19Z. The page's practica-list query ran past the 10s statement_timeout and was killed. It is a heavy-tailed query sitting 13x below the timeout on average, so any slowdown pushes it over. WHAT WAS KILLED (Supabase postgres_logs, parsed.query): 7 cancels in two bursts. Burst 1, 12:25:03.28-.41Z: 3x the practica list query (PRACTICA_LIST_CTES, src/lib/practica.ts:161) plus 1x get_comision_picked_teachers. Burst 2, the retry, 12:25:19.74-.89Z: 3x the practica list query only. Each render fires several variants of the list query in parallel, which is why each burst has 3. NORMAL BEHAVIOUR OF THE SAME QUERY (pg_stat_statements since 2026-09-10, top 4 variants by calls): mean 604-815ms, max 3.1-5.8s, stddev about equal to the mean (533-962ms). That spread is a heavy tail, not a stable cost. A page that fires 3 or 4 of these at once sits close to the 10s limit whenever the DB slows at all. LIKELY CAUSE, A HYPOTHESIS NOT YET MEASURED: both CTEs aggregate their ENTIRE tables with no filter. teeth_agg is `SELECT practicaId, array_agg(toothNumber) FROM vPracticaTeeth GROUP BY practicaId`, and image_agg is the same shape over practicaImages. If the outer query's filter or page is not pushed through the GROUP BY (join conditions from a LEFT JOIN normally are not), every call aggregates teeth and images for all practicas to return one page. CONFIRM WITH EXPLAIN (ANALYZE, BUFFERS) on the real text of one variant before changing anything. The fix direction is to aggregate only the practicaIds on the page, e.g. LATERAL subqueries or filtering the CTE by the same predicate. Per the Postgres-boundary rule this may belong in a DB view or function, so involve db03-mars-ca if so. THE STALL QUESTION (MARS-729 alert 2 / MARS-690), recorded honestly because it cuts both ways. Burst 1 looks like a stall: pg_cron job 6, scheduled for 12:25:00, did not start until 12:25:07.5, and get_comision_picked_teachers, normally fast, was killed alongside the list queries. Burst 2 ran at 12:25:09-19, after cron had recovered, and killed only the heavy query. A checkpoint with write=11.4s finished at 12:21:46, three minutes earlier, not overlapping. So: not a clean isolated kill, and not cleanly inside a stall either. What it points at is QUERY WEIGHT, not the connection layer. A lighter query would have survived both bursts. MARS-690 stays parked on this evidence. ACCEPTANCE: the EXPLAIN evidence is on this row, and the list query's max over a week of normal traffic is well below 10s, measured by pg_stat_statements after a stats reset, not claimed.
Activity
-
Read-only EXPLAIN (ANALYZE, BUFFERS) from db-mars-cc confirmed the actual default getScopedPracticas page-1/50 query spends ~478ms of 837ms in unfiltered teeth_agg/image_agg full-table aggregates (4,139 and 15,688 rows). coder03-mars-ca is implementing a page-scoped aggregate fix; no DB migration applies.
-
EXPLAIN: planning 110ms, total 837ms, shared-hit=5396/no disk I/O. teeth_agg GroupAggregate Seq Scan practicaTeeth 4,139 rows ~152ms; image_agg HashAggregate Seq Scan practicaImages 15,688 rows ~325ms. The outer LEFT JOIN does not push page predicate into CTE GROUP BY. Evidence supplied read-only by db-mars-cc; binds redacted.
-
Implementation independently audited PASS by audit-general-cc and published by coder03-mars-ca in fb2d0a7 (v2.79.76). Pre-push gate: 70 test files, 836 tests passed. Production health remained on v2.79.75 immediately after push; rollout verification pending. Status stays inProgress because the acceptance criterion requires a week of post-release pg_stat_statements evidence.
-
Runtime deployment verified at 2026-09-15T03:42:12Z: https://mars-evolutiva.pensanta.com/api/health returned HTTP 200, version 2.79.77, deployment dpl_3tPt3QG6kKBnawhJB43Q9tjHojhU, Node v24.19.0. Status remains inProgress for the explicitly required week of post-release pg_stat_statements evidence.
-
support-evolutiva-cc 2026-09-28: measured headroom on the CTE query this row names. pg_stat_statements has the scoped_candidates MATERIALIZED CTE at 29 calls, mean 792ms, max_exec_time 6935ms against mars_app_runtime's statement_timeout=10000 - so the observed peak sits 3.1s under the cap, and a burst walks it over. It went over at 21:30:43-21:31:15Z tonight; full burst evidence and the pool-checkout tail are on MARS-743. Two caveats on that 6935ms so it is not quoted as a ceiling: the counters are low (29 calls), so this is a short window since the last reset, not a month; and a statement cancelled by the timeout is not necessarily recorded by pg_stat_statements at all, so the true max is >= the 10s cap, not 6935ms.
-
coder-mars-cc
-
support-evolutiva-cc 2026-09-28: reassigned coder03-mars-ca -> coder-mars-cc, same reason as MARS-743: coder03-mars-ca is not in the hub roster, so an inProgress p1 was held by an unreachable seat.
-
coder-mars-ca / coder
-
coder-mars-ca
-
support-evolutiva-cc 2026-09-28: assignee corrected coder-mars-cc -> coder-mars-ca per db-mars-ca's ownership note (db-mars-ca-mulrufqby1e3). My earlier move off the unreachable coder03-mars-ca seat was a reachability fix, not an ownership judgement; the lane has now named the seat that owns the list follow-up. db-mars-cc retains the detail bundle.
-
2026-10-06: Current source already has the 2026-09-15 page-scoped teeth/image aggregate fix (fb2d0a7), but later production bursts still canceled scoped_candidates list variants at the 10s statement_timeout. Current query and page fan-out inspected; requested read-only production EXPLAIN on the largest real comisión from db-mars-ca before changing app SQL. This seat's Supabase execute_sql returned permission denied, so DB lane is measuring. Acceptance remains worst-comisión before/after plus PTD and unexercised-load statement.
-
2026-10-06 read-only production EXPLAIN (ANALYZE, BUFFERS, FORMAT JSON), current source getScopedPracticas, v2.85.9 / HEAD c97cf42. Largest active vPracticas comisión: 135a6b1c-5b9c-4727-8e6b-8e626875c3b5, 796 rows; 17 active teacher memberships. Page 1/50, default ordering, comisionId filter applied to both variants. Teacher-member scope: planning 193.290 ms, execution 365.299 ms (second execution observation 661.318 ms), 4000 shared-hit blocks, 0 reads; scope_kpis aggregate 191.186 ms / 2940 hits over 796 candidates is main cost. Full-access: planning 93.417 ms, execution 236.293 ms, 3964 hits, 0 reads; scope_kpis 87.353 ms / 2910 hits. Full plan vPracticaTeeth seq scan 4971 rows, 116 removed, 45 ms. Neither approached app role statement_timeout=10000ms (live pg_roles rolconfig confirmed); these are single runs, not a weekly max/ceiling. Read-only; no DB changes.
-
2026-10-06 candidate projection benchmark (read-only), same max comisión and page 1/50/default sort as baseline. Candidate excludes reviewedAt/calificacion from scoped_candidates. EXPLAIN ANALYZE teacher: planning 311.8ms, execution 538.8ms, 4000 shared hits/0 reads; full access: planning 7.1ms, execution 18.8ms, 3964 hits/0 reads. Prior baseline samples: teacher 193.3/365.3ms, full 93.4/236.3ms; separate sessions, not paired (pooler backend warmth may differ), so timings do not establish latency regression/improvement. Critical plan check: idx_practicaReviews_practicaId still executes 796 loops over scoped candidates plus 50 for returned page in BOTH candidate plans; latest-review LATERAL work did not disappear. Same-snapshot comparison: page 1 IDs/order mismatch=0 for teacher and full access; KPI equality true both, 796 total / 752 approved / 1 rejected / 23 pending / 20 rectificar. Candidate is output-equivalent, <10s, but misses intended loop reduction; no DB changes.
-
2026-10-06 candidate 2, read-only full-projection EXPLAIN on same production commission/page1/50/default order. Current base-practicas + periodos/lookup candidate source: teacher planning 236.5ms/execution 378.7ms, 1324 shared hits/0 reads; full access 6.8ms/12.6ms, 1288 hits/0 reads. Latest-review idx_practicaReviews_practicaId now 50 loops (page fetch only), 138 hits; previous vPracticas candidate path had 796 scoped-candidate loops + 50 page loops and 2676 review-index hits. Baseline whole-query samples 193.3/365.3ms teacher, 93.4/236.3ms full; separate/unpaired connections, so timing deltas are not causal (backend warmth not controlled). Same-snapshot equivalence: default first-50 ordered IDs mismatch=0 and KPIs equal for teacher+full; full-access state=noRevisado filter: 23 rows, mismatch=0/KPIs equal; teacher sort=calificacion review-dependent: mismatch=0/KPIs equal. All candidate samples under 10s; no DB writes. Focused app tests reported by coder 5/5; not rerun here.
-
Runtime-role deployment gate (read-only, 2026-10-06): has_table_privilege('mars_app_runtime', relation, 'SELECT') returned true for public.practicas, public.periodos, public."lookupOptions", public.users, and public.comisiones. Attempted BEGIN READ ONLY; SET LOCAL ROLE mars_app_runtime; denied: permission denied to set role mars_app_runtime. No EXPLAIN under runtime role was possible with agent_db_mars_ca; no grants or DB writes made. Privilege checks pass; runtime-role EXPLAIN remains unverified.
-
2026-10-06 SHA 457749825c1079e1c6cd95ac6bb6c3aaabd04f4b, v2.85.10 pushed to origin/main via clean isolated clone; shared checkout fast-forwarded. Production PTD: GitHub commit-specific Vercel status success/Production at 03:45:35Z, target deployment 4yrXbcTyiMbuJFbRsgzJhMrse8b1; /api/health at 03:46:13Z returned 2.85.10 and dpl_4yrXbcTyiMbuJFbRsgzJhMrse8b1, matching remote main package version. Full clean-tree gate: 81 files, 974 tests passed; focused query tests 5/5. Largest real comisión 135a6b1c-5b9c-4727-8e6b-8e626875c3b5 (796 prácticas): same-snapshot page IDs/order and KPI tuples match for teacher/full default, full state=noRevisado, teacher calificacion sort. Candidate latest-review index loops fell from 796+50 to 50; shared hits 4000->1324 teacher and 3964->1288 full; 0 physical reads. Candidate plan/exec teacher 236.5/378.7ms, full 6.8/12.6ms, both under 10s. Prior samples 193/365ms teacher and 93/236ms full, unpaired and backend warmth uncontrolled, so no causal latency-delta claim. Not exercised: authenticated production /practicas render under the app role, cold backend, concurrent peak traffic, or required week of pg_stat_statements maxima; cancelled statements may not appear in those maxima. Runtime SELECT grants verified true on five tables, SET LOCAL ROLE denied to read-only seat. Keep inProgress for production-traffic and weekly-max evidence.
-
Post-push independent review: audit-general-ca PASS:457749825c1079e1c6cd95ac6bb6c3aaabd04f4b deep/2c, source-only. Reviewer confirmed committed query/test diff matches pre-push scope review; package.json is version-only. Reviewer did not rerun live same-snapshot DB comparisons or runtime-role execution. Production PTD and measurement limits remain as recorded in the 2026-10-06 verified event.
-
2026-10-06 closure-instrument check from coder-mars-ca: Supabase execute_sql SELECT against pg_stat_statements returned MCP permission denied; this seat has no DATABASE_URL or seat-local Postgres credential. It therefore cannot run the original week-max query or appEvents fallback directly today. Requested a mode-600 read-only Mars credential from db-mars-ca (no DB grant/rotation). Exact repeatable query and attainable closure condition will be recorded after that response; do not treat either instrument as available yet.
-
Credential availability for repeatable closure measurement (2026-10-06): local ~/.config/postgres/db-mars-ca.env is mode 600 and connects as agent_db_mars_ca. This read-only role successfully SELECTs public."appEvents" and extensions.pg_stat_statements. No separate coder-mars-ca credential exists in the local credential set; did not copy/relabel the db-mars-ca login, which would misattribute DB activity. A distinct login requires authorized provisioning; no grants/credential changes made.
-
2026-10-06 PM routing correction: coder-mars-ca's request for a copied/read-only credential is withdrawn; no credential is to move between seats. db-mars-ca owns the attributed SELECT-only closure reads using its existing access: post-4577498 practica-list pg_stat_statements calls/mean/max, and appEvents statement-timeout occurrences since 2026-09-14. Exact SQL and results must be stored on this row. If pg_stat_statements is denied to that role, record role+denial and rely only on the attainable appEvents signal, with its weaker coverage stated. No DB grants/DDL or code changes.
-
2026-10-06 closure instrument read, source HEAD 457749825c1079e1c6cd95ac6bb6c3aaabd04f4b. Connected as agent_db_mars_ca; pg_stat_statements SELECT succeeded (not permission-denied). stats_reset=2026-09-28 03:57:55.062625Z. Query returned matching_practica_list_stats=[] (0 rows/calls after reset for historical queryid 578895516455647848 or current scoped_candidates SQL); therefore no current calls/mean/max to report, not an instrument denial. Exact query 1 (READ ONLY): SELECT i.stats_reset, coalesce(jsonb_agg(jsonb_build_object('queryid',q.queryid,'calls',q.calls,'mean_exec_time_ms',round(q.mean_exec_time::numeric,2),'max_exec_time_ms',round(q.max_exec_time::numeric,2)) ORDER BY q.calls DESC) FILTER (WHERE q.queryid IS NOT NULL),'[]'::jsonb) AS matching_practica_list_stats FROM extensions.pg_stat_statements_info i LEFT JOIN extensions.pg_stat_statements q ON q.queryid=578895516455647848 OR q.query ILIKE '%scoped_candidates%' GROUP BY i.stats_reset; Exact query 2 predicate/output: appEvents since 2026-09-14 00:00Z where errorMessage ILIKE '%canceling statement due to statement timeout%'; aggregate rows, server/client category rows, practica-route rows, rows since stats_reset (2026-09-28 03:57:55.062625Z), min/max createdAt. Result: 182 matching rows; 176 category server/client; 82 practica route classes; 11 since stats_reset; first 2026-09-14 12:25:03.910877Z, last 2026-10-05 11:51:08.087704Z. These are event rows, not unique incidents or proof all are the list query; appEvents has broad route/action coverage. Both queries ran inside BEGIN READ ONLY/ROLLBACK; no writes.
-
Exact appEvents SQL from the 2026-10-06 read (the preceding evidence note summarized rather than transcribed it): WITH timeout_events AS (SELECT id, "createdAt", category, action, CASE WHEN route='/practicas' THEN '/practicas' WHEN route ~ '^/practicas/[0-9a-fA-F-]{36}(/|$)' THEN '/practicas/[id]' WHEN route LIKE '/practicas%' THEN '/practicas/other' ELSE 'other' END AS route_class FROM public."appEvents" WHERE "createdAt">=timestamptz '2026-09-14 00:00:00+00' AND "errorMessage" ILIKE '%canceling statement due to statement timeout%') SELECT count(*) AS exact_timeout_error_rows, count(*) FILTER (WHERE category IN ('server','client')) AS client_or_server_error_rows, count(*) FILTER (WHERE route_class LIKE '/practicas%') AS practica_route_rows, count(*) FILTER (WHERE "createdAt">=timestamptz '2026-09-28 03:57:55.062625+00') AS since_pgss_reset, min("createdAt") AS first_at, max("createdAt") AS last_at FROM timeout_events; Output: 182 / 176 / 82 / 11; first 2026-09-14 12:25:03.910877Z, last 2026-10-05 11:51:08.087704Z. READ ONLY transaction.
-
Repeat run 2026-10-06 (agent_db_mars_ca, BEGIN READ ONLY/ROLLBACK); exact SQL repeated unchanged from prior notes: SELECT i.stats_reset, coalesce(jsonb_agg(jsonb_build_object('queryid',q.queryid,'calls',q.calls,'mean_exec_time_ms',round(q.mean_exec_time::numeric,2),'max_exec_time_ms',round(q.max_exec_time::numeric,2)) ORDER BY q.calls DESC) FILTER (WHERE q.queryid IS NOT NULL),'[]'::jsonb) AS matching_practica_list_stats FROM extensions.pg_stat_statements_info i LEFT JOIN extensions.pg_stat_statements q ON q.queryid=578895516455647848 OR q.query ILIKE '%scoped_candidates%' GROUP BY i.stats_reset; WITH timeout_events AS (SELECT id, "createdAt", category, action, CASE WHEN route='/practicas' THEN '/practicas' WHEN route ~ '^/practicas/[0-9a-fA-F-]{36}(/|$)' THEN '/practicas/[id]' WHEN route LIKE '/practicas%' THEN '/practicas/other' ELSE 'other' END AS route_class FROM public."appEvents" WHERE "createdAt">=timestamptz '2026-09-14 00:00:00+00' AND "errorMessage" ILIKE '%canceling statement due to statement timeout%') SELECT count(*) AS exact_timeout_error_rows, count(*) FILTER (WHERE category IN ('server','client')) AS client_or_server_error_rows, count(*) FILTER (WHERE route_class LIKE '/practicas%') AS practica_route_rows, count(*) FILTER (WHERE "createdAt">=timestamptz '2026-09-28 03:57:55.062625+00') AS since_pgss_reset, min("createdAt") AS first_at, max("createdAt") AS last_at FROM timeout_events; Repeat results unchanged: pg_stat reset 2026-09-28 03:57:55.062625Z; matching stats []; appEvents 182 exact errorMessage rows, 176 server/client, 82 /practicas route classes, 11 since reset; first 2026-09-14 12:25:03.910877Z, last 2026-10-05 11:51:08.087704Z. pg_stat SELECT succeeded; zero match, not denied.
-
2026-10-06 closure-read caveat: db-mars-ca SELECT on extensions.pg_stat_statements succeeds, but queryid/text filter for historical list query/current scoped_candidates returned zero rows despite appEvents recording /practicas timeouts since stats reset. This is NOT evidence of zero calls; canceled statements may be absent and a non-pg_read_all_stats role may have other users' queryid/text hidden. Requested a read-only visibility-control census of app-role rows, NULL identifiers/text and pg_read_all_stats membership before accepting pg_stat_statements as a named closure instrument.
-
Visibility control requested by coder-mars-ca, 2026-10-06; READ ONLY as agent_db_mars_ca. Result: current_user=agent_db_mars_ca; pg_read_all_stats membership=false; 983 total pg_stat_statements rows, 920 have NULL queryid and query NULL/<insufficient privilege>; mars_app_runtime has 249 rows / 96,799 calls, all 249 with NULL queryid and hidden query text. Thus pg_stat_statements is callable but cannot identify app-role statements from this seat; previous empty match is NOT evidence of zero calls and is not a usable closure instrument. Exact SQL: WITH target_role AS (SELECT oid FROM pg_roles WHERE rolname='mars_app_runtime'), all_stats AS (SELECT count(*) AS total_rows, count(*) FILTER (WHERE queryid IS NULL) AS null_queryid_rows, count(*) FILTER (WHERE query IS NULL OR query='<insufficient privilege>') AS hidden_query_rows FROM extensions.pg_stat_statements), app_stats AS (SELECT count(*) AS rows, coalesce(sum(calls),0) AS calls, count(*) FILTER (WHERE queryid IS NULL) AS null_queryid_rows, count(*) FILTER (WHERE query IS NULL OR query='<insufficient privilege>') AS hidden_query_rows FROM extensions.pg_stat_statements WHERE userid=(SELECT oid FROM target_role)) SELECT current_user, pg_has_role(current_user,'pg_read_all_stats','member') AS pg_read_all_stats_member, (SELECT total_rows FROM all_stats) AS total_pgss_rows, (SELECT null_queryid_rows FROM all_stats) AS null_queryid_rows, (SELECT hidden_query_rows FROM all_stats) AS hidden_query_rows, (SELECT rows FROM app_stats) AS mars_app_runtime_rows, (SELECT calls FROM app_stats) AS mars_app_runtime_calls, (SELECT null_queryid_rows FROM app_stats) AS mars_app_runtime_null_queryid_rows, (SELECT hidden_query_rows FROM app_stats) AS mars_app_runtime_hidden_query_rows. No privilege/grant changes. Existing appEvents exact-timeout-text read remains available; no claim that it substitutes for the hidden weekly max query.
-
2026-10-06 closure-instrument decision: agent_db_mars_ca can SELECT extensions.pg_stat_statements but lacks pg_read_all_stats; 249 mars_app_runtime rows / 96,799 calls have hidden queryid and query text. Therefore the original list-query weekly max is NOT identifiable under this role; the zero matching rows were a visibility artifact, not zero calls. No credential/grant change. Per PM fallback, use the attainable user-visible signal: for the seven days after the exact production deployment (2026-10-06 03:45:35Z through 2026-10-13 03:45:35Z), require zero appEvents statement-timeout rows on the exact /practicas list path. Standing SQL: SELECT count(*) AS list_timeout_rows FROM public."appEvents" WHERE "createdAt" >= timestamptz '2026-10-06 03:45:35+00' AND "createdAt" < timestamptz '2026-10-13 03:45:35+00' AND split_part(coalesce(route,''),'?',1) = '/practicas' AND "errorMessage" ILIKE '%canceling statement due to statement timeout%'; Run with a concurrent SELECT count(*) of all appEvents in the window as telemetry-activity context; zero event rows means no coverage, not a pass. This is weaker than query max: error writes can be lost during DB distress, successful list loads are not logged, and no list-traffic denominator exists. A zero only supports 'no captured list timeouts in the window', not guaranteed latency below 10s under peak load. If no timeout-free week or event rail is silent, keep open/escalate; do not call the SQL-performance criterion proven.
-
Standing gate executed once 2026-10-06 under agent_db_mars_ca in BEGIN READ ONLY/ROLLBACK. Early-window check only; not closure. Exact standing SQL: SELECT count(*) AS list_timeout_rows FROM public."appEvents" WHERE "createdAt" >= timestamptz '2026-10-06 03:45:35+00' AND "createdAt" < timestamptz '2026-10-13 03:45:35+00' AND split_part(coalesce(route,''),'?',1) = '/practicas' AND "errorMessage" ILIKE '%canceling statement due to statement timeout%'; Result 0. Exact telemetry-activity context SQL: SELECT count(*) AS all_event_rows FROM public."appEvents" WHERE "createdAt" >= timestamptz '2026-10-06 03:45:35+00' AND "createdAt" < timestamptz '2026-10-13 03:45:35+00'; Result 12. Timestamp companion SQL used the identical predicate as the standing query and selected max("createdAt") AS last_observed_list_timeout_at; result NULL (no matching event). Zero is only no captured list timeout so far; window has run about one hour and is not a pass.
-
2026-10-06 privacy-safe exposure census, READ ONLY as agent_db_mars_ca. Predicate is the same 82-row census: createdAt >= 2026-09-14 00:00Z AND route LIKE '/practicas%' AND errorMessage ILIKE '%canceling statement due to statement timeout%'. Result: 82 rows; distinct actorUserId=2, distinct effectiveUserId=0, distinct coalesce(effectiveUserId,actorUserId)=2; 80 rows have no actorUserId, all 82 have no effectiveUserId and no sessionId, distinct sessionId=0. Therefore there are two observed actor identities but unique-person reach and session counts are UNKNOWN, not 2 people / 0 sessions. Exact identity/timing SQL: WITH timeout_events AS (SELECT id, "createdAt", "actorUserId", "effectiveUserId", "sessionId" FROM public."appEvents" WHERE "createdAt">=timestamptz '2026-09-14 00:00:00+00' AND route LIKE '/practicas%' AND "errorMessage" ILIKE '%canceling statement due to statement timeout%') SELECT count(*), count(DISTINCT "actorUserId"), count(DISTINCT "effectiveUserId"), count(DISTINCT coalesce("effectiveUserId","actorUserId")), count(*) FILTER (WHERE "actorUserId" IS NULL), count(*) FILTER (WHERE "effectiveUserId" IS NULL), count(DISTINCT "sessionId"), count(*) FILTER (WHERE "sessionId" IS NULL), min("createdAt"), max("createdAt"), timestamptz '2026-10-06 03:45:35+00'-max("createdAt") FROM timeout_events; Exact cluster method: same timeout_events CTE, then ordered adds new_cluster=1 when lag(createdAt) is null or current-createdAt minus lag > interval '5 minutes'; clustered assigns sum(new_cluster) over (ORDER BY createdAt,id); GROUP BY cluster_id returns count(*), min/max createdAt, count distinct actorUserId/effectiveUserId/sessionId. This yields 21 clusters, tuples UTC start..end (rows): 09-14 12:25:03.910877..12:25:19.773236 (2); 09-16 13:45:08.840525 (1); 09-16 18:14:26.519087 (1); 09-16 18:22:58.300760..18:28:06.118581 (5); 09-16 23:04:09.780684..23:04:59.827605 (9); 09-18 01:14:53.847502..01:16:14.512972 (4); 09-19 15:23:13.470714 (1); 09-21 23:03:36.449146..23:05:01.926351 (11); 09-21 23:24:26.131028 (1); 09-22 02:15:15.412323..02:15:37.883853 (4); 09-22 13:23:09.673215..13:24:15.219564 (9); 09-23 13:17:16.953697..13:17:32.918730 (4); 09-23 20:30:22.133091..20:31:06.090106 (3); 09-24 22:50:52.248630 (1); 09-25 10:35:21.244064..10:35:21.623725 (2); 09-25 13:32:06.234111..13:33:33.924204 (3); 09-25 14:05:19.828589..14:05:21.163329 (2); 09-27 20:14:12.430074..20:14:24.049164 (4); 09-27 20:33:31.897651..20:37:27.456709 (9); 09-28 21:30:43.845322..21:31:07.767610 (4); 10-05 11:50:09.752971..11:51:08.087704 (2). A 5-minute gap defines clusters; these are event clusters, not proven incident boundaries. Last timeout precedes recorded 4577498 production deployment 2026-10-06 03:45:35Z by 15:54:26.912296. Documented identity/pgss blind spots in mars/shared/md/mars-unverifiable-state.md. No PII emitted, no writes.
-
2026-10-06 route/identity split and burst census (READ ONLY, agent_db_mars_ca). Same timeout predicate as the 82-row census: createdAt >= 2026-09-14 00:00Z; route LIKE '/practicas%'; errorMessage contains exact PostgreSQL statement-timeout text. Classification after stripping query string: exact /practicas = list, literal /practicas/[id] or UUID segment = detail, remaining /practicas paths = other. Results: list 39 rows / 0 distinct actor IDs / 39 actor NULL / 0 effective IDs / 39 effective NULL / 0 detail.clientSession / 39 NULL; detail 40 / 1 actor ID / 39 actor NULL / 0 effective IDs / 40 NULL / 0 clientSession / 40 NULL; other 3 / 1 actor ID / 2 actor NULL / 0 effective IDs / 3 NULL / 0 clientSession / 3 NULL. Across 82: only 2 event rows carry actorUserId (2 distinct values), all 82 have effectiveUserId and detail.clientSession NULL. Unique-user reach is UNKNOWN; no session-based attribution. Exact route-class query: WITH base AS (SELECT id, "createdAt", "actorUserId", "effectiveUserId", detail->>'clientSession' AS client_session, split_part(coalesce(route,''),'?',1) AS route_path FROM public."appEvents" WHERE "createdAt">=timestamptz '2026-09-14 00:00:00+00' AND route LIKE '/practicas%' AND "errorMessage" ILIKE '%canceling statement due to statement timeout%'), classified AS (SELECT *, CASE WHEN route_path='/practicas' THEN '/practicas list' WHEN route_path='/practicas/[id]' OR route_path ~ '^/practicas/[0-9a-fA-F-]{36}/?$' THEN '/practicas/[id]' ELSE '/practicas other' END AS route_class FROM base) SELECT route_class,count(*),count(DISTINCT "actorUserId"),count(*) FILTER(WHERE "actorUserId" IS NULL),count(DISTINCT "effectiveUserId"),count(*) FILTER(WHERE "effectiveUserId" IS NULL),count(DISTINCT client_session),count(*) FILTER(WHERE client_session IS NULL),min("createdAt"),max("createdAt") FROM classified GROUP BY route_class ORDER BY route_class; Exact burst rule/query: reuse base+classified CTE above; ordered AS (SELECT *, CASE WHEN lag("createdAt") OVER(PARTITION BY route_class ORDER BY "createdAt",id) IS NULL OR "createdAt"-lag("createdAt") OVER(PARTITION BY route_class ORDER BY "createdAt",id)>interval '5 minutes' THEN 1 ELSE 0 END AS new_cluster FROM classified), clustered AS (SELECT *,sum(new_cluster) OVER(PARTITION BY route_class ORDER BY "createdAt",id) AS cluster_id FROM ordered) SELECT route_class,cluster_id,count(*),min("createdAt"),max("createdAt"),count(DISTINCT "actorUserId"),count(DISTINCT "effectiveUserId"),count(DISTINCT client_session) FROM clustered GROUP BY route_class,cluster_id ORDER BY route_class,min("createdAt"); Results: 15 exact-list clusters (39 events), 11 detail clusters (40), 2 other-path clusters (3), each split when same-route gap exceeds 5m. Full cluster UTC boundaries/counts are the 28 rows from the 2026-10-06 04:46Z run: list clusters start 09-14 12:25:03.910877 (2); 09-16 13:45:08.840525 (1); 09-16 18:14:26.519087 (1); 09-16 18:22:58.300760..18:28:06.118581 (5); 09-19 15:23:13.470714 (1); 09-21 23:03:36.449146..23:04:05.726421 (8); 09-21 23:24:26.131028 (1); 09-22 02:15:15.412323..02:15:34.592359 (3); 09-22 13:24:06.711164..13:24:15.219564 (4); 09-23 13:17:16.953697..13:17:32.918730 (4); 09-25 10:35:21.244064 (1); 09-25 13:32:06.234111..13:33:33.924204 (3); 09-27 20:37:21.093804 (1); 09-28 21:30:43.845322..21:31:07.518070 (3); 10-05 11:51:08.087704 (1). Detail clusters: 09-16 23:04:09.780684..23:04:59.827605 (9); 09-18 01:14:53.847502..01:16:14.512972 (4); 09-21 23:04:40.035885..23:05:01.926351 (3); 09-22 02:15:37.883853 (1); 09-22 13:23:09.673215..13:23:18.917939 (5); 09-23 20:30:22.133091..20:31:06.090106 (3); 09-25 10:35:21.623725 (1); 09-27 20:14:12.430074..20:14:24.049164 (4); 09-27 20:33:31.897651..20:37:27.456709 (8); 09-28 21:31:07.767610 (1); 10-05 11:50:09.752971 (1). Other: 09-24 22:50:52.248630 (1); 09-25 14:05:19.828589..14:05:21.163329 (2). Events across route classes may share incident windows; clusters are a timing heuristic only. Last event query used same base predicate with SELECT max("createdAt"), timestamptz '2026-10-06 03:45:35+00'-max("createdAt") FROM public."appEvents"; result 2026-10-05 11:51:08.087704Z, 15:54:26.912296 pre-deploy. No identifiers/PII returned. Full boundary series and aggregate counts stored; no DB writes.
-
Exact route-specific burst SQL actually executed 2026-10-06 (READ ONLY): WITH base AS (SELECT id, "createdAt", "actorUserId", "effectiveUserId", detail->>'clientSession' AS client_session, split_part(coalesce(route,''),'?',1) AS route_path FROM public."appEvents" WHERE "createdAt">=timestamptz '2026-09-14 00:00:00+00' AND route LIKE '/practicas%' AND "errorMessage" ILIKE '%canceling statement due to statement timeout%'), classified AS (SELECT *, CASE WHEN route_path='/practicas' THEN '/practicas list' WHEN route_path='/practicas/[id]' OR route_path ~ '^/practicas/[0-9a-fA-F-]{36}/?$' THEN '/practicas/[id]' ELSE '/practicas other' END AS route_class FROM base), ordered AS (SELECT *, CASE WHEN lag("createdAt") OVER(PARTITION BY route_class ORDER BY "createdAt",id) IS NULL OR "createdAt"-lag("createdAt") OVER(PARTITION BY route_class ORDER BY "createdAt",id)>interval '5 minutes' THEN 1 ELSE 0 END AS new_cluster FROM classified), clustered AS (SELECT *,sum(new_cluster) OVER(PARTITION BY route_class ORDER BY "createdAt",id) AS cluster_id FROM ordered) SELECT route_class,cluster_id,count(*) AS event_rows,min("createdAt") AS cluster_start,max("createdAt") AS cluster_end,count(DISTINCT "actorUserId") AS actor_ids,count(DISTINCT "effectiveUserId") AS effective_ids,count(DISTINCT client_session) AS client_sessions FROM clustered GROUP BY route_class,cluster_id ORDER BY route_class,cluster_start; Exact last-event/deploy comparison SQL: SELECT max("createdAt") AS last_timeout_at, timestamptz '2026-10-06 03:45:35+00' - max("createdAt") AS before_deploy FROM public."appEvents" WHERE "createdAt">=timestamptz '2026-09-14 00:00:00+00' AND route LIKE '/practicas%' AND "errorMessage" ILIKE '%canceling statement due to statement timeout%'; Results: 15 list clusters/39 rows, 11 detail clusters/40 rows, 2 other clusters/3 rows; cluster threshold >5 minutes within each route class. Last event 2026-10-05 11:51:08.087704Z; 15:54:26.912296 before production deployment. Exact outputs/boundaries recorded in preceding 04:50:47Z note. No DB writes.
-
Scope confirmation per PM 2026-10-06: the standing 2026-10-06..2026-10-13 gate is exact-list-only. Predicate split_part(coalesce(route,''),'?',1) = '/practicas' excludes '/practicas/[id]' and every other /practicas path. The broader route LIKE '/practicas%' predicate is used only for the historical 82-row census, not the seven-day gate. One-hour result remains 0 list-timeout rows with 12 all-event rows; not closure.
-
Observation gate until 2026-10-13 03:45:35Z: 4577498/v2.85.10 list CTE fix is live; close only after running the recorded exact-list-route statement-timeout query for 2026-10-06 03:45:35Z..2026-10-13 03:45:35Z and reporting exposure/coverage. Day-one zero is not seven-day evidence. pg_stat_statements app-role query text is hidden to current read-only role; db-mars-ca holds the appEvents standing read.
-
coder-mars-cc
bug
4w ago by wi-cli-venus
6d ago