mars
MARS-698
Mars unreachable 2026-09-05 22:10-22:43Z: postgres accepted no connections on four independent paths
Done high
cmcoder-mars-cc
Second outage of the same class as MARS-688, 12 hours after it. dbOk:false on /api/health?db=1 at 22:41:00Z, 22:41:18Z and 22:41:35Z on v2.79.26 dpl_7vbUSykMZuhAuPXRBmE6bPTR7GGQ. DATABASE_URL was the postgres role throughout - unrelated to the mars_app_runtime cutover, which has not been retried. Four independent clients failed in the same window: the Vercel app pool, Supabase MCP (Connection terminated due to connection timeout), venus applog-pull at 22:40:29Z with ECHECKOUTTIMEOUT after 15000ms in Session mode, and db-mars-cc direct psql on 5432 which hung 15s with no refuse. No app-side pool setting can explain a failure on a client outside Vercel using its own pool, so this is Supabase-side. Supabase status read Partially Degraded Service as of 20:28:59Z; the only unresolved incident listed is an unrelated JWT one from August. Recovered on its own by 22:43:23Z, stable across six probes to 22:47:43Z. Nothing was changed to recover it - no redeploy, no env change, no rotation. Onset bounded between 22:10Z and 22:40Z: applog-pull finished clean at 20:10, 20:40, 21:10, 21:40 and 22:10. THE MEASUREMENT THAT MATTERS: appEvents holds ZERO error rows across the whole 3-hour window covering the outage. The app could not log its own unavailability because logging is itself a database write. That is audit-mars-ca's MARS-689 P1 finding reproduced in production rather than argued from code, and it means the true recurrence count of this class is unknown and unmeasurable from our own telemetry.
Activity
-
STILL FLAPPING, not resolved. Timeline in UTC: dbOk false 22:41:00 22:41:18 22:41:35, true 22:43:23 through 22:47:43, student 500 on /mi-cursada at 22:49:29 (ECHECKOUTTIMEOUT after 15000ms in Transaction mode), false 22:51:00, true 22:51:45 through 22:52:51, a plain psql query of mine timed out at 90s around 22:53, applog-pull failed again at 23:10:21 with the same Session-mode ECHECKOUTTIMEOUT, false 23:10:28 and 23:11:03, true 23:11:38. So the window is at least 22:10 to 23:11 UTC with repeated recoveries, not a single outage. Supabase status still reads Partially Degraded Service. Nothing changed on our side at any point - no redeploy, no env change, no migration, no rotation. Elazar asked by CLI; a Supabase support ticket needs his word because it is outward-facing on his account.
-
Ongoing at 23:41Z, 90 minutes in. Third consecutive applog-pull failure at 23:40:29Z, same Session-mode ECHECKOUTTIMEOUT. Health false at 23:40:35 and 23:41:06, true at 23:41:23. The pattern is now well established and stable in shape: the database is reachable most of the time and unreachable in bursts of roughly one to several minutes, recurring every few minutes, for at least 90 minutes. The 30-minute applog-pull timer has hit a bad window three times in a row, which is a coincidence of cadence, not an escalation. Still nothing changed on our side.
-
Stable since 00:03Z. Health checked 14:06:13Z, dbOk true, no recurrence in roughly 14 hours. appEvents over the last 16 hours holds exactly TWO rows: the single 22:00Z error (the student 500 on /mi-cursada during the flap) and one unrelated client-side warn today. That is the whole telemetry record of a 90-minute intermittent database outage - one row - which is the MARS-689 P1 blindness quantified rather than argued. Leaving the WI open: the cause was never established, it was Supabase-side and outside our reach, and a second occurrence within 12 hours of MARS-688 means the recurrence interval is not yet known.
-
Recurrence 2026-09-07 21:56:56Z: one student 500 on /mi-cursada with ECHECKOUTTIMEOUT after 15000ms in Transaction mode. Isolated - health probes at 21:57:39Z and after all return dbOk true, and it is the only error row in three hours. Same class as the 2026-09-05 event and MARS-688, now a third occurrence across four days, so the pattern is brief pool-checkout stalls recurring at an interval we still cannot bound. Note on the row itself: errorName reads 'error' because node-pg errors carry that literal name, so the MARS-689 errorName fix works but adds nothing for this class - the discriminator stays the message string. Worth knowing before anyone builds grouping on errorName for DB failures.
-
Fourth occurrence, and this one is a multi-minute window not an isolated stall. 2026-09-07: student 500 at 21:56:56Z, then applog-pull failed at 22:10:33Z with Session-mode ECHECKOUTTIMEOUT, and health returned dbOk false at 22:10:38, 22:10:51, 22:11:45, 22:12:37 and 22:13:30, recovering at 22:14:22Z. So roughly a 4-minute unreachable window, same shape as 2026-09-05 - both the app pool and the venus session-mode client down together, nothing changed on our side, self-recovering. Supabase status still reads Partially Degraded Service. Interval between events so far: 2026-09-04 (MARS-688), 2026-09-05, 2026-09-07 twice. It is recurring on a roughly daily cadence and the cause remains outside our reach.
-
Fifth window tonight: applog-pull failed again at 22:40:32Z, health dbOk false at 22:40:39Z, recovered by 22:41:25Z - under a minute this time. Tonight's sequence: 21:56 student 500, 22:09 student 500, 22:10-22:14 four-minute outage, 22:40-22:41 brief outage. Two students took 500s. The cadence has tightened from once a day to roughly every 30 minutes this evening, though note the 30-minute applog-pull timer is itself a 30-minute sampler, so the true frequency may be higher and the timer is simply the only thing looking. Health probes between my own checks are not continuous either. Nothing changed on our side at any point.
-
23:40:32Z window is DIFFERENT in shape and worth separating from the others. applog-pull failed again with Session-mode ECHECKOUTTIMEOUT, and my own psql through the transaction pooler also hung past 60s at the same moment - but the app stayed UP throughout: dbOk true at 23:40:43, 23:41:11 and 23:41:37. Previous windows took the app down together with the venus client. So this one is not simply a shorter version of the same thing: either the degradation is partial and hits new connections rather than warm ones, or the app's own pool was already holding usable connections and never had to check out a new one. The 23:11:04 run finished clean, so the failures are not continuous. Not asserting a mechanism - recording that a same-signature failure occurred with the app unaffected, which none of the earlier windows did.
-
DECISIVE INSTRUMENT, from db-mars-cc: cron.job_run_details. 26 failed runs between 2026-09-07 21:45:00Z and 23:40:00Z, every one with return_message 'job startup timeout'. That reframes tonight: not four discrete windows but ONE continuous ~2-hour degradation, during which the app coped intermittently because warm pooled connections kept working. pg_cron runs as in-process background workers and never traverses Supavisor, so a startup timeout is the Postgres instance failing to launch a worker - compute-side, not connection-side, and not reachable by any app or pooler setting. This is the same family as MARS-688's checkpoint stall with write=85.144s. It also gives us the observation window we lacked: cron.job_run_details records these events even when appEvents cannot, because it is written by the scheduler rather than by the app. Any future measurement of this class should start there, not from appEvents. Duration trend across occurrences: 09-04 MARS-688, 09-05 ~90 minutes, 09-07 ~2 hours. Growing.
-
Fourth consecutive night, and the timing is now the finding. Tonight 2026-09-08: applog-pull failed 22:40:30Z, health dbOk false at 22:40:43Z, my psql died mid-session with ECHECKOUTTIMEOUT in Transaction mode plus SSL connection closed unexpectedly, one probe at 22:43:17Z failed outright, recovered by 22:41:20 and stable from 22:44. THE WINDOWS CLUSTER AT THE SAME TIME OF DAY: 09-05 22:10-23:41Z, 09-07 21:45-23:40Z (26 cron job startup timeouts), 09-08 from 22:40Z. Three nights, all starting between 21:45 and 22:40 UTC and running to roughly 23:40 UTC. That is 18:45-20:40 ART, which is peak student usage, but a load explanation does not fit a pg_cron worker startup timeout - and it also matches the shape of a nightly provider-side maintenance or backup window. Not asserting which; recording that the recurrence is time-of-day bound rather than random, because that is the single most useful fact for a Supabase support ticket and it took four nights of observation to see.
-
Tonight is a continuous window too, confirmed by the cron instrument rather than by probes: 13 consecutive failed cron runs from 22:15:00Z through 23:10:00Z, with the last success at 22:10:00Z. So 2026-09-08 ran 22:15Z to at least 23:10Z. That is now four nights with the same onset band - 09-05 from 22:10Z, 09-07 from 21:45Z, 09-08 from 22:15Z - all ending near 23:40Z. The app-level picture stayed misleadingly good throughout: dbOk true at 23:10:29Z while cron had been failing for 55 minutes straight, which is the warm-pool effect again. Anyone reading health probes alone would have called tonight two brief blips. Read cron.job_run_details, not appEvents and not the health endpoint.
-
2026-09-09 07:10-07:11Z: FIRST occurrence OUTSIDE the 21:45-23:40Z nightly band. applog-pull@mars.service failed 07:10:35Z with ECHECKOUTTIMEOUT after 15000ms in Session mode (direct :5432, bypasses Mars transaction pool). /api/health?db=1 dbOk:false at 07:11:01Z and 07:11:19Z, then dbOk:true at 07:11:48Z and 07:12:08Z - a ~1 minute window, far shorter than the nightly 90min-2h events. Supabase MCP execute_sql could not reach cron.job_run_details at all across three attempts in the same window (Connection terminated due to connection timeout), so the instrument was itself unavailable - a fifth independent client failing on a fresh connection. Time-of-day clustering is now WEAKENED: onsets are not confined to the evening band. Nothing app-side changed; no deploy since v2.79.26.
-
2026-09-09 07:10-07:46Z, DAYTIME, INTERMITTENT: the stall class is no longer confined to the 21:45-23:40Z band and no longer looks like one continuous outage. applog-pull@mars.service failed twice consecutively (07:10:35Z, 07:40:34Z) with ECHECKOUTTIMEOUT after 15000ms in Session mode on direct :5432. Dense probing of /api/health?db=1 at 7s spacing shows a DUTY CYCLE, not a window: dbOk:false 07:11:01-07:11:19, true 07:11:48-07:12:08; false 07:40:56-07:41:48, true 07:42:15-07:42:41; one curl HUNG past a 20s deadline at ~07:44:00; false continuously 07:44:18-07:45:50 (six probes, 92s), true from 07:46:01 onward (five probes). HYPOTHESIS TESTED AND REJECTED: that the failures merely coincide with applog-pull's :10/:40 run minute - the 07:44-07:45 run of six consecutive failures is four minutes off any sampler boundary, so the two instruments are independent. Supabase MCP execute_sql could not reach cron.job_run_details on four attempts spanning both failing and healthy probe moments, so MCP is NOT a usable instrument for this and its failure is not evidence either way. No deploy since v2.79.26; nothing app-side changed.
-
2026-09-09 07:52-08:11Z: still failing, now ~60 minutes into the daytime episode. dbOk:false on three probes 07:52:57-07:53:32Z and four probes 08:10:49-08:11:42Z. applog-pull@mars.service failed a third consecutive run at 08:10Z. Supabase status page at 07:59:27Z: indicator=minor, 'Partially Degraded Service' - the same posture it has carried through every prior window, so it neither confirms nor excludes Mars's project. This episode is longer and in student hours (04:52-05:11 ART is not, but the 07:10Z onset means the duty cycle has now run through the whole morning UTC).
-
2026-09-09 08:40Z: fourth consecutive applog-pull@mars.service failure; dbOk:false on three probes 08:40:43-08:41:18Z. Episode now 91 minutes old (onset 07:10Z) and still cycling - it recovered briefly at 08:23:14Z and failed again within 17 minutes. This is the longest continuous duty-cycle episode measured and the first that spans a full working morning UTC. Escalated to Elazar four times; the Supabase support ticket decision is still unanswered.
-
2026-09-09 09:10Z: fifth consecutive applog-pull@mars.service failure at 09:10Z, but dbOk:true on three probes 09:10:43-09:11:04Z - the app path recovered while the direct :5432 Session-mode client did not. Same split seen on 09-07 23:40Z. Episode ran 07:10Z to at least 08:53Z (103 min of intermittent failure) before the app path came back. Supabase status unchanged at 'Partially Degraded Service'.
-
2026-09-09 09:27:58Z: STUDENT-FACING 500. appEvents id=b8a2f413-ac05-489a-94d3-e302d44171ad, server/unhandled-server-error on /mi-cursada/a78ec1dc-9be3-4658-8ae9-8dcfcf8adf6a: ECHECKOUTTIMEOUT after 15000ms in Transaction mode - the app's own :6543 pool, 17 minutes after the app path had read healthy at 09:11:04Z. That the row exists at all means the write path was momentarily up; per this WI's standing caveat, appEvents undercounts and the true count of student 500s in this episode is at least this one. Running total of student-visible failures: 09-05 (1), 09-07 (2), 09-09 (1+).
-
2026-09-09 10:06-10:09Z: episode now in its FOURTH hour (onset 07:10Z) and deepening. db-mars-cc reports 7 consecutive failed connection attempts on direct :5432 across 10:06:39-10:07:44Z. My own probes: one /api/health?db=1 call HUNG past a 20s deadline with zero bytes received - the route itself, not just its DB branch - then dbOk:false at 10:08:48Z and 10:09:06Z. The hung call is the second of its kind today (first ~07:44Z) and is a harder signal than dbOk:false: the health handler's own response did not come back.
-
2026-09-09 11:10Z: ninth consecutive applog-pull@mars.service failure; dbOk:false on three probes 11:10:51-11:11:26Z. Episode is now FOUR HOURS old (onset 07:10Z) with no sustained recovery - by far the longest measured, and the first to run through a working day rather than overnight. Nine consecutive 30-minute sampler points have failed, so the direct :5432 path has not been reliably reachable at ANY point in four hours. Supabase status unchanged: 'Partially Degraded Service'.
-
2026-09-09 12:40Z: cron.job_run_details FINALLY READ - the instrument confirms the compute-side diagnosis and contradicts the app probe. Last 20 runs, 11:15:00Z through 12:40:00Z, are ALL 'failed | job startup timeout' with ZERO successes - Postgres has been unable to launch a pg_cron background worker for at least 85 continuous minutes. Critically, the 12:40:00Z cron run failed at the same moment /api/health?db=1 returned dbOk:true on three consecutive probes (12:40:33-12:40:53Z). That is the sharpest instance yet of the standing caveat on this WI: the health probe is served by warm pooled connections and reports healthy straight through a total failure to establish new work. Any duration or recurrence figure taken from the probe is a floor, not a measurement. Getting this read cost 8 psql attempts across an hour; wider aggregates over the same table were cancelled at a 25s statement_timeout every time, so only an ORDER BY runid DESC LIMIT tail is reachable during an episode.
-
2026-09-09 13:53:26Z: SECOND student-facing 500 today. appEvents id=28006ecd-8cc8-4af8-9fdb-f4af99d8cf54, server/unhandled-server-error on /practicas/1c9ca334-3d64-4eb5-88cb-88bfa8906e8a, ECHECKOUTTIMEOUT after 15000ms in Transaction mode. First was 09:27:58Z on /mi-cursada. Both are the app's own :6543 pool failing to obtain a server connection from Supavisor - the same signature as the 09-04 incident, and NOT our client pool (our connectionTimeoutMillis is 10000, so the 15000ms budget is Supavisor's; see MARS-691's verified correction). Episode running 07:10Z to 13:53Z, now 6h43m. Running total of student-visible failures: 09-05 (1), 09-07 (2), 09-09 (2+ and counting). appEvents undercounts by construction, so these are floors.
-
2026-09-09 15:20Z: cron STILL 100% failing - 'job startup timeout' unbroken from 11:15Z through 15:20Z, over four continuous hours with zero pg_cron worker launches, read while /api/health?db=1 reported dbOk:true at 15:10:36Z and 15:10:46Z. Fifteen consecutive applog-pull@mars.service failures. No cron job has run on this project today. The app-path/cron-path split is now the stable shape of this episode rather than a transient: warm pooled connections serve, new work cannot be established. Episode 07:10Z-15:20Z, 8h10m, longest by a wide margin and still open.
-
2026-09-09 18:58:11Z: THIRD student-facing 500 today, and it carries a DIFFERENT error signature worth separating. appEvents id=f7367ca8-101e-46f3-9c1b-49226be49db8 on /mi-cursada/14bd812b-ee48-4d67-9fdc-eeb3d9896f04?_rsc=... reads 'Connection terminated due to connection timeout' - that string is pg-pool 3.14.0's own (node_modules/.pnpm/pg-pool@3.14.0_pg@8.22.0/node_modules/pg-pool/index.js:276), NOT Supavisor's. Per MARS-691's verified correction the two are distinguishable: ECHECKOUTTIMEOUT/15000ms is Supavisor failing to get a server connection, while this message is OUR client hitting its own connectionTimeoutMillis=10000 before reaching the pooler at all. Today has produced both - 09:27:58Z and 13:53:26Z were the Supavisor signature, this one is ours. Do NOT read that as pool exhaustion on our side: the same upstream stall makes connection ESTABLISHMENT slow, so our 10s budget expires for the same root cause. Student-visible failures: 09-05 (1), 09-07 (2), 09-09 (3+).
-
2026-09-09 19:21:17Z: FOURTH student-facing 500 today. appEvents id=009da617-d4f0-467d-a819-5ab84fd5a292, ECHECKOUTTIMEOUT after 15000ms in Transaction mode on /practicas/7fadc107-596b-4644-a563-b1dccfc7c251 - Supavisor signature, same as 09:27:58Z and 13:53:26Z. This one lands at 16:21 ART, inside evening peak student hours, with the episode now 12h11m old (onset 07:10Z) and no sustained recovery. Student-visible failures: 09-05 (1), 09-07 (2), 09-09 (4+). Today alone has produced twice as many as the two prior nights combined, and appEvents undercounts by construction so every figure here is a floor.
-
2026-09-09 19:28:14Z: FIFTH student-facing 500 today. appEvents id=909117d3-0b13-4b19-a507-97ea472017f3, ECHECKOUTTIMEOUT 15000ms Transaction mode on /mi-cursada/7440c2b1-e8b5-4bdf-abce-d12dd592350f - seven minutes after the fourth. Two student failures inside seven minutes is the tightest clustering measured in this incident and lands squarely in evening peak (16:21 and 16:28 ART). Twenty-third consecutive applog-pull failure at 19:42Z. Episode 12h32m. Student-visible: 09-05 (1), 09-07 (2), 09-09 (5+).
-
2026-09-09 21:10Z: twenty-sixth consecutive applog-pull@mars.service failure. The episode that began at 07:10Z has now run FOURTEEN HOURS and has merged straight into the 21:45-23:40Z nightly band without ever clearing. This retires the last of the original shape: not a nightly window, not time-of-day bound, and not self-limiting at 90min-2h. Five student-facing 500s recorded today across /mi-cursada and /practicas, in both the Supavisor (ECHECKOUTTIMEOUT) and pg-pool (connection terminated) signatures. Nothing app-side has changed since v2.79.26 on 09-05.
-
2026-09-09 23:23:15Z: SIXTH student-facing 500 today. appEvents id=b13129ea-5e49-49aa-a5ba-6d4f4dbfc3f2, ECHECKOUTTIMEOUT 15000ms Transaction mode on /mi-cursada/fc028202-8e92-4c2a-8444-1d29d62f1e1b, 20:24 ART. Episode 16h13m and unbroken since 07:10Z; thirty consecutive applog-pull failures. Student-visible totals: 09-05 (1), 09-07 (2), 09-09 (6+) - today is three times the two prior nights combined, and appEvents undercounts by construction so it is a floor. The Supabase support ticket decision has been put to Elazar on every one of today's escalations and remains unanswered; per the standing rule it is his account and outward-facing, so no ticket has been opened.
-
2026-09-10 01:15Z-06:10Z: NEW AND DISTINCT SYMPTOM, independently confirmed with db-mars-cc. The 09-09 episode ENDED - cron.job_run_details shows 'succeeded | 1 row' at 00:55, 01:00 (x2), 01:05, 01:10 and 01:15:01Z, the first successes since before 11:15Z on 09-09. Then the table STOPS: zero rows of any kind after 01:15:01Z against a read at 06:09Z, a five-hour total gap on drain-email-outbox (*/5 min, active=t) and every other schedule. This is NOT the 'job startup timeout' signature - those were logged FAILED launch attempts. Total absence means no launch is being attempted at all; db-mars-cc reports cron.launch_active_jobs=on, jobs active=t, and no cron launcher visible in pg_stat_activity. Path shape has also narrowed: direct db.<ref>:5432 hard-hangs at 15s with zero response while the session pooler and the app both connect fine (/api/health?db=1 dbOk:true at 06:09:57Z) - unlike 09-07/09-09 where all paths failed together. Blast radius check: "emailOutbox" has ZERO unsent rows and no row created since 2026-09-08 22:07Z, so nothing is currently queued behind the stalled drain job - the exposure is that nothing WOULD drain if a mail were queued now, not a present backlog. Treat as an escalation of the same incident class, not a repeat.
-
Recurrence 2026-09-10 ~07:40Z, and a SUB-MINUTE duty cycle measured across two independent agents. db-mars-cc at 07:40Z: direct :5432 hard timeout (15s, zero response); session pooler :5432 FATAL auth-did-not-complete-within-15000ms; /api/health?db=1 itself timed out (curl exit 28, 0 bytes, 15s). Plain /api/health returned fine with dbOk:null, so the app tier was up and only the DB-touching path failed - consistent with the established finding that degradation is in ESTABLISHING NEW WORK, not the database being gone. My own probes minutes later, same event: dbOk:true at 07:40:48Z, 07:40:56Z and 07:41:05Z, all three healthy. So a 15s zero-response timeout and a healthy db=1 probe occurred inside the SAME MINUTE from two agents. This is the third independent confirmation of the duty cycle rather than a window, and the tightest alternation measured so far - previous dense probing on 09-09 showed runs of 20-90s, this is under 60s. Consequence, worth stating because it invalidates the obvious triage: a single healthy db=1 probe is not evidence the episode ended, and a single failing one is not evidence it is ongoing. Any duration on this WI is a floor. Do not close an episode on one probe. db-mars-cc touched nothing. Ticket remains Elazar's call.
-
2026-09-10 08:40Z episode captured live, and it yields a BETTER INSTRUMENT than dbOk alone. applog-pull@mars (venus systemd timer, 30-min cadence) is now a usable sampler for this: 07:40Z FAILED (ECHECKOUTTIMEOUT 15000ms, Session mode, direct :5432 - Supavisor's budget, not ours), 08:10Z CLEAN ('no new warn events since 2026-09-09 16:25:05Z'), 08:40Z FAILED with the identical signature. Two failures an hour apart with a clean run between them. My probes immediately after the 08:40 failure: dbOk:false at 08:40:55Z, 08:41:12Z and 08:41:30Z, then dbOk:true at 08:41:37Z. A ~55s failing run recovering within 7s of the last failure - consistent with the sub-minute duty cycle measured at 07:40Z. THE LATENCY IS THE INSTRUMENT, not the boolean. Each dbOk:false response carried a server ts ~16s AFTER the request left (08:40:39 -> ts 08:40:55, 08:41:02 -> 08:41:12, 08:41:19 -> 08:41:30), i.e. the probe sat through the full pool checkout timeout before answering false. The dbOk:true response came back in under a second (08:41:37 -> ts 08:41:37). So round-trip time separates a healthy checkout from a stalled one, and unlike the boolean it should also expose PARTIAL degradation - a checkout that eventually succeeds after seconds still reports dbOk:true and is invisible to every count on this WI so far. Any future sampler on this WI should record elapsed time per probe, not just dbOk. Blast radius this episode: none observed beyond the failed sampler run. App tier up throughout, version 2.79.27 served on every probe including the failing ones.
-
MAJOR LEAD, and it contradicts the standing 'cause is outside our reach, nothing we do affects it' framing on this WI. Surfaced 2026-09-10 via nw-whey-ca relaying db-mars-ca relaying Elazar: Supabase reported Mars NEAR DISK IO BUDGET DEPLETION with pool pressure, alongside a 'mystery backup repeatedly downloading Mars'. Disk IO budget depletion fits EVERY observation on this WI, which no previous hypothesis did: - pg_cron 'job startup timeout': Postgres failing to LAUNCH a background worker is what an IO-starved instance does, and it is why the failure is compute-side and unreachable by any pool size or connection string. - MARS-688's checkpoint writing 32KB with write=85.144s - an absurd figure for that volume, and exactly what throttled-to-baseline IOPS looks like. - The DUTY CYCLE. A burst-credit model throttles to baseline when the budget empties and releases when credits partially refill. That produces alternating 20-90s failing and healthy runs - a duty cycle, not a window - which is precisely what dense probing measured on 09-09 and again on 09-10. - Four independent clients failing together including a DIRECT :5432 connection: consistent, because the constraint is the instance's IO, not Supavisor. - 'Self-recovers every time': credits refill. AND IT SUPPLIES A PLAUSIBLE CONSUMER. A backup repeatedly pulling a full copy of the database is exactly the workload that drains an IO burst budget. evolutiva-backup@mars.timer was a real twice-daily pg_dump (nw-whey-ca verified, latest run 13,981,935 bytes, healthy). Whether that timer, some other repeated download, or ordinary load is the actual drain is NOT established - do not record it as settled. What IS established is that a mechanism now exists which explains the shape, and it is potentially within our control. ACTION TAKEN: evolutiva-backup@mars.timer disabled --now by nw-whey-ca on db-mars-ca's relayed instruction from Elazar. Narrow and reversible - that timer only; service, unit, drop-in, run.sh, credentials, artifacts and every other Mars timer untouched, existing dumps intact. THIS IS ALSO AN UNINTENDED EXPERIMENT, so treat it as one. If MARS-698 episodes stop or thin out over the next 24-48h with the timer off, that is evidence the backup was a major IO consumer. If they continue unchanged, the backup is exonerated and the drain is elsewhere. Either result is worth more than the guess. Record episodes with ELAPSED TIME PER PROBE, not just dbOk - a checkout that eventually succeeds after seconds still reports dbOk:true and is invisible otherwise. COST OF THE EXPERIMENT, standing: Mars now has NO scheduled backup while MARS-700 (production refusing all writes) is open. Flagged to Elazar; nw-whey-ca is holding as-is and will not re-enable without his explicit direction. If MARS-700 proves to be a bad config change, the last good dump is what makes it recoverable.
-
CAUSE LINE ESTABLISHED, and this WI's long-standing 'compute-side, outside our reach, unexplained' framing is now superseded. See MARS-700 for the measurement. Mars's instance has 7,568 MB of WAL across 474 files against a 131 MB database, with pg_replication_slots EMPTY - nothing is holding it. WAL that cannot be recycled produces continuous write and checkpoint pressure, which is the mechanism behind the Disk IO Budget depletion and pool pressure Supabase reported. That single cause fits every property this WI has measured and no previous hypothesis fit even most of them: - pg_cron 'job startup timeout': an IO-starved instance cannot launch a background worker. Compute-side, unreachable by pool size or connection string - exactly as recorded. - MARS-688's checkpoint writing 32 KB with write=85.144s: absurd for that volume, ordinary for throttled IO. - The DUTY CYCLE, runs of 20-90s failing alternating with healthy: burst-credit exhaustion and partial refill, not a maintenance window. - Four independent clients failing together including a DIRECT :5432 that bypasses Supavisor entirely: the constraint is the instance's IO, so every client is affected regardless of path. - 'Self-recovers every time; nothing we changed caused or fixed any of it': credits refill; nothing we changed touched WAL. The provider-maintenance-window hypothesis this WI carried is not needed and should not be quoted further. Still unknown, and not determinable from SQL on this surface: WHY WAL is not being recycled with no slot pinning it. Candidates are checkpointing falling behind or WAL ARCHIVING FAILING - a stuck archive_command accumulates WAL indefinitely, and Supabase's PITR/backup machinery is a WAL archiver. checkpoint state and archive_command status are not queryable here. That is the question for the Supabase ticket, which is Elazar's to file. CONSEQUENCE FOR THE BACKUP EXPERIMENT: evolutiva-backup@mars.timer was disabled on the theory that repeated full dumps were draining the IO budget. That may still have contributed, but it is now clearly not the primary cause - WAL accumulation is upstream of it. Do not read a reduction in episodes over the next 24-48h as proof the backup was the cause, and do not leave Mars unbacked on the strength of that theory. Re-enabling is Elazar's call; the case for re-enabling is now stronger than when it was paused.
-
CAUSE FOUND AND FIXED - closing on MARS-700's measurement, which answered the exact question this WI left open. This WI's last note said the cause line was established but that ONE thing was not determinable from SQL on this surface: WHY WAL was not being recycled with no replication slot pinning it, with a stuck WAL ARCHIVER named as the leading candidate and a Supabase ticket named as the way to find out. No ticket was needed. MARS-700 measured it directly on 2026-09-10: WAL-G's wal-push had failed on a SINGLE segment since 2026-09-08 23:46:49Z, 2504 consecutive attempts, and Postgres never recycles a segment it has not archived. That is the stuck archiver, confirmed rather than hypothesised, and it is upstream of every symptom recorded here - the pg_cron job-startup timeouts, MARS-688's checkpoint writing 32KB with write=85.144s, the 20-90s duty cycle, four independent clients failing together including a direct :5432 that bypasses Supavisor, and the self-recovery with nothing we changed. Fixed by a Supabase dashboard project restart at 09:28:15Z: the archiver unwedged immediately, WAL drained from 7568MB/474 files to 96MB/7 files in about eight minutes, and the forced read-only cleared itself. Mars sits at 6 WAL files with failed_count 0 and an archive rate of about 25 segments/hour as of 2026-09-11, against a known-healthy fleet of venus 7, terra 9, pluto 16. TWO THINGS THAT MUST NOT BE LOST IN THE CLOSE. 1. THE BACKUP EXPERIMENT IS RESOLVED, AND ITS PREMISE WAS FALSE. evolutiva-backup@mars.timer was disabled on the theory that repeated full dumps were draining the IO burst budget. That theory is now falsified - the drain was unarchivable WAL, which the backup neither caused nor influenced. This WI explicitly warned not to leave Mars unbacked on the strength of that theory, and as far as I can determine the timer is STILL DISABLED, which means Mars has had no scheduled backup for six days. Re-enabling is Elazar's call and I have surfaced it; the case is now strictly stronger than when it was paused, because the reason for pausing is gone. 2. THE INSTRUMENT LESSON SURVIVES THIS WI. Record ELAPSED TIME PER PROBE, never dbOk alone: a checkout that eventually succeeds after seconds still reports dbOk:true and is invisible to every count. During the 08:40Z episode each dbOk:false carried a server ts ~16s after the request left, i.e. the probe sat through the full Supavisor checkout budget, while the healthy response returned in under a second. And separately: a read-only probe CANNOT detect a write outage at all, which is why this class ran ~24h before anything noticed. Closed by coder-mars-cc as PM. No reviewer verdict exists and none can - audit-mars-ca is off the roster.
-
Cross-ref MARS-752 2026-09-20: a 23:22Z statement-timeout burst coincided with a PostgREST heartbeat gap of 59.7s vs ~33s (one beat missing); no lock/vacuum in postgres_logs. Same stall family; dashboard CPU/IO/memory for 23:21-23:23Z still unread.
-
2026-09-20 23:32:11-23:32:57Z second stall in 10 min (db-mars-cc, postgres_logs + live sample 23:33:27Z): 24 cancels, all mars_app_runtime, 15 get_practica_detail_bundle + 9 others (4 vPracticas reads, conductos, paciente/tipoDocumento, users lookup, an INSERT INTO appEvents). No lock wait, no checkpoint, no restart (uptime 914712s), live sample 0 lock waits. PostgREST heartbeat gap 78.8s (one beat missing). Same shape as 09-16 23:04. Cause (host CPU/IO) unreadable from any agent lane; dashboard CPU/IO/memory for 23:21-23:23Z and 23:32-23:33Z is a human read. MARS-752 per-practica reading is dead.
-
2026-09-21 22:55:40-22:56:23Z third stall (db-mars-cc, postgres_logs): 17 cancels, 16 get_practica_detail_bundle + 1 INSERT INTO appEvents (a cancelled write, invisible in appEvents by construction). Heartbeat gap 78.7s. Checkpoint completed 22:56:56 wrote 266 buffers (~2 MB) with write=41.2s = ~6 buffers/s; began inside the burst (symptom, not trigger). Same signature as 09-04 (4 buffers, write=85s). Baseline checkpoints same night also slow: 121 buffers 12.1s, 136 buffers 13.8s, 113 buffers 11.4s (~10 buffers/s, ~80 KB/s). Supports: storage write path slow/throttled, stalls are its worst moments. NOT proven: cause (disk IO budget/throttle vs host contention). Human read needed: Supabase Reports > Database > Disk IO (IOPS + throughput vs compute-tier limit / burst balance) for 09-20 23:21-23:33Z and 09-21 22:55-22:57Z, plus current compute size. If IO is at the tier ceiling the fix is compute/disk tier, not SQL.
-
2026-09-21 23:03:17-23:03:37Z fourth stall in 3 days (second tonight, 8 min after 22:55): 15 cancels, all mars_app_runtime, mixed statements (6x practica LIST scoped_candidates, 3x json_agg, 3x empty text, 1x bundle) - not bundle-dominated. Live sample 23:04:51Z: 0 lock waits, longest 0.46s, DB answering again. CAVEAT: postgres_logs stream ends 23:03:37.33 while db-mars-cc's own query ran 23:04:51 => no heartbeat/checkpoint data after 23:03:44 (ingestion lag or logger stall, undetermined). Auth failure 'did not complete within 15000ms' 23:04:05 and ECHECKOUT rows fall after that horizon: unconfirmed, not established whether pooler/auth failed independently. Pattern so far: stalls at ~23:00-23:33Z (20:00-20:33 ART) on 09-20 and 09-21; three days too few to call a schedule. Dashboard Disk IO read still outstanding.
-
2026-09-21 ~23:09-23:10Z re-read (db-mars-cc): postgres_logs stream still ends 23:03:37.33; >6 min with zero lines (expected ~11 heartbeat beats) while the DB answered live queries at 23:04:51 and ~23:09. Log shipping stopped when the burst began (or the pipeline stalled with it). Cannot measure heartbeat, auth failure or checkpoint after 23:03:37 from postgres_logs; only app-side rows and live pg_stat_activity remain. Another platform-level signal for the dashboard ask; not proof of cause. db-mars-cc re-reads once when the stream resumes, on poke.
-
CORRECTION (db-mars-cc retraction 2026-09-21 20:12 ART): my earlier note that postgres_logs shipping halted at 23:03:37Z is WRONG. It was ingestion lag of a few minutes; the stream backfilled with original timestamps. Drop 'log shipping halted'. What holds: logs arrive minutes late during/after a burst. Measured now: 09-21 hard DB-wide stall ~23:03:20-23:05:10Z (heartbeat 23:03:11.6->23:05:10.9 = 119.3s, ~3 beats missing), 46 cancels 23:03:27-23:05:19.5 incl. ECHECKOUT, auth-15000ms and breaker open 23:05:02. Checkpoint 23:01:14 wrote 283 buffers in 29.3s (~10/s). Cause (IO limit vs host vs platform) still unproven; dashboard Disk IO read for 23:03:20-23:05:10Z is the sharpest ask.
-
6915913 (v2.79.83) live: db-breaker-close appEvents row (info tier, detail openDurationMs first-trip-to-close + finalCooldownMs). audit-general-cc PASS:6915913 static+tests. Its non-blocking notes: (a) query_timeout bounds execution not checkout, so on a saturated pool the close INSERT can wait as a pool waiter up to 10s and inflate waiting in the next trip's telemetry (same as the open row); (b) pre-existing: any non-acquisition success, including one admitted before the trip, closes the breaker, so a close row can follow a very short open; (c) swallow-on-reject verified by reading, not by test. Close row absent != breaker still open.
bug
5w ago by wi-cli-venus
5w ago
2026-09-11 10:31