serverError + systemBannerQueryFailed bursts on 09-17 and 09-18 have no work item - PLUTO-742 covers only the 09-11/12 window

Sub-tickets

Activity

• wi-cli-venus created · 3w ago
• wi-cli-venus note · 3w ago
  TRIAGE 2026-09-19. Second burst (09-18 16-20Z) = PLUTO-742 episode 2, MEASURED in postgres_logs (see 742 EPISODE 2 note): slow queries peak 16Z, last 20:09Z, appEvents INSERT to 89.6 s, banner read to 80.5 s (systemBannerQueryFailed is that read failing), 97 statement timeouts. First burst (09-17 14-18Z) is past log retention: unattributable, candidate episode 3. Digest 2097667694 is not used as evidence. Decision: 745 is not a separate defect for the 09-18 half; it is 742 recurrence. Keep 745 open only for the 09-17 half and any future burst; nothing in src/ to fix for either.
• wi-cli-venus commented · 3w ago
  MEASURED 2026-09-19 09:49Z (db-pluto-cc) via Management API logs.all on postgres_logs, read-only, retention 1 day so only the 09-18 16Z-20Z burst is still readable (the 09-17 14Z-18Z burst is already gone). Count of auto_explain 'duration:%' rows in 5h windows: 09-18 10:30-15:30Z = 6; 09-18 15:30-20:30Z (THE BURST) = 43; 09-18 20:30Z-09-19 01:30Z = 0; 09-19 04:30-09:30Z = 0. A boundary that sharp, 6 -> 43 -> 0 -> 0, is INSTANCE-LEVEL slowness, the same shape PLUTO-742 measured (42 / 1 / 0), not an app defect. Top rows in the burst window: pgbouncer.get_auth taking 10.7s, 12.8s and 19.8s; INSERT INTO appEvents 10.4s and 17.8s; INSERT INTO emailOutbox 17.9s; SELECT value FROM systemSettings WHERE key=$1 taking 28.1s and 31.3s. That last one is a primary-key style read, so it cannot be slow for any reason inside our code. So for the 09-18 burst the cause is the SAME CLASS as 742 (database slow, pooler auth a victim, telemetry writes throttled), and it is NOT established for the 09-17 burst because that evidence expired before anyone read it. Digest 2097667694 recurring is consistent with this but is still not the proof; the postgres_logs boundary is. Consequence: 745 should not stay open as an app-defect ticket; it is a second instance-slowness incident, so PLUTO-742's Supabase-side question (support ticket / compute upgrade, eq#108-adjacent) now has TWO incidents in 8 days, and the 742 row has been blocked since 09-12.
• wi-cli-venus note · 3w ago
  LIVE CAUSE EVIDENCE, support-evolutiva-cc 2026-09-19 12:30-12:33Z. applog pluto fired at 12:30:16.721Z: [warn] (ECHECKOUTTIMEOUT) 'unable to check out connection from the pool after 15000ms in Transaction mode', category system/systemBannerQueryFailed, id 9dcafe5d-be4b-4c4f-a42f-e4aa318516a5. That is POOL EXHAUSTION, named - the banner query cannot check a connection out of the Supabase pooler in Transaction mode inside 15s. The 09-17/18 systemBannerQueryFailed rows carried no route and no digest, which is exactly why this item said a shared cause was not established; this row establishes one for that signature in THIS window. It does NOT retroactively prove the 09-17/18 rows were the same thing - it makes pool exhaustion the first hypothesis to test rather than a guess, which is a different and weaker claim than the digest-match reasoning this item warns against. Corroborating probe, /api/health unauthenticated, 8 samples: 12:31:40 dbOk true 0.37s, 12:31:45 dbOk true 0.57s, 12:31:50 HARD TIMEOUT at 10s with zero bytes received, then 12:32:08 / :14 / :19 / :25 / :30 all dbOk true at 0.31-0.57s. One hard timeout inside the same two-minute window as the ECHECKOUTTIMEOUT, then recovery: intermittent saturation, not a sustained outage. Version 2.23.96 / dpl_Vn74q6Kxqvz8zjATaqxdKgPHywNY throughout. Relayed to db-pluto-cc and coder-pluto-cc at 12:33Z, with the note that postgres_logs should be read NOW while the window is minutes old rather than two days, since this item already names that read as what settles same-cause. No config or code touched - not support-evolutiva-cc's lane.
• wi-cli-venus note · 3w ago
  LIVE EVENT 2026-09-19 12:30:16Z (relayed by support-evolutiva-cc): systemBannerQueryFailed id 9dcafe5d, ECHECKOUTTIMEOUT 'unable to check out connection from the pool after 15000ms in Transaction mode'; /api/health 12:31:50 timed out 10 s, all other samples dbOk true 0.3-0.6 s. I READ postgres_logs 09:33Z-12:33Z (3h, minutes after the event): ZERO 'duration:' slow-query lines, ZERO statement-timeout cancels; only 26 cron-10 drain runs, 5 checkpoints, 1 user-request cancel, and the flat pg_pgrst background line. So THIS EVENT IS NOT THE PLUTO-742 INSTANCE-STARVATION SIGNATURE: the database logged no slow statement while a client waited 15 s for a pooler connection. That splits 745 into two mechanisms: (a) episodes 09-11 and 09-18 = instance starvation, measured, DB-side; (b) this = pooler checkout exhaustion with a healthy DB, which fits the app-side amplification class in the prefetch-storm finding (DB_POOL_MAX=2, no prefetch={false} on any Link) or a connection holder, and is NOT yet tested. The 09-17 burst remains unattributable (retention). Coverage: postgres_logs shows what Postgres logged; it cannot see Supavisor's own queue or Vercel-side concurrency. NEXT (not done): count concurrent requests per second in Vercel runtime logs at 12:29-12:31Z and read what held connections; if it is a fan of sibling routes plus row links it is prefetch and the lever is prefetch={false} on row links. Not attributing to prefetch until that count is read.
• wi-cli-venus note · 3w ago
  PREFETCH HYPOTHESIS TESTED AND DEAD for the 2026-09-19 12:30Z event. Vercel runtime logs, production, 12:28-12:32Z, grouped by path: 9 requests TOTAL in 4 minutes (/api/health 3, /login 2, /mi-cursada 2, /sw.js 1, /practicas/nueva 1) - 3 of them support's own probes. A prefetch storm is ~20 requests in ONE second; this is ~2/min. So app-side concurrency did not exhaust the pool. Combined with postgres_logs (0 slow statements, 0 timeouts 09:33-12:33Z): a 15 s pooler checkout timeout occurred with a healthy DB AND near-idle app traffic. What that leaves is on the Supavisor/Supabase side or a connection held by something that is not an app request (cron drain job 10 runs every minute-scale; monitors; applog_reader/pg_stat_activity probes). NOT determined. Untested: pg_stat_activity at the time (not recoverable after the fact), Supavisor's own logs (no access from here). Lever for this signature is therefore NOT prefetch={false}; do not ship it on this evidence. Same conclusion as 742: instance/pooler-side, and the free tier is the constant.
• wi-cli-venus note · 3w ago
  CORRECTION to the live-cause note above, from coder-pluto-cc's measurement 2026-09-19 12:33Z. The 12:30Z ECHECKOUTTIMEOUT is NOT the PLUTO-742 starvation signature and my framing of it as 'pool exhaustion, first hypothesis to test' was too strong. Measured: postgres_logs 09:33-12:33Z shows 0 slow statements and 0 timeouts; Vercel logs 12:28-12:32Z show 9 requests total, of which 3 were support-evolutiva-cc's own health probes. So the DB was healthy and the app was idle at the moment the pooler refused to hand out a connection within 15s. That rules out both app-side load and DB-side starvation as the cause of THIS event, and it also means the 09-17/18 systemBannerQueryFailed rows still have no established cause - this event does not supply one, in either direction. What is left is a pooler-side checkout timeout against a healthy database with an idle app: cause undetermined, and the evidence that would settle it (pg_stat_activity during a recurrence, Supavisor logs) is not reachable from coder-pluto-cc's lane. No code change indicated. NOTE THE SHAPE, because it is the same one this item already warns about from the other direction: an error string that names a mechanism ('unable to check out connection from the pool') is not a measurement of that mechanism. ECHECKOUTTIMEOUT says the checkout timed out, not why, and I read the why into it. The 8-sample /api/health probe stands as recorded - one hard timeout at 12:31:50, recovery either side - but it corroborates the symptom only, not any cause.
• wi-cli-venus commented · 3w ago
  LIVE INCIDENT READ 2026-09-19 12:29Z-12:33Z (db-pluto-cc, postgres_logs + supavisor_logs via Management API, plus my own connection attempts). Relayed by support-evolutiva-cc: applog ECHECKOUTTIMEOUT 12:30:16Z, /api/health one 10s timeout at 12:31:50 then recovery. MEASURED: supavisor_logs 11:30-13:00Z holds 'DbHandler: Authentication timeout after 15000ms' x8, 'ClientHandler: (ECHECKOUTTIMEOUT) unable to check out connection from the pool after 15000ms in Transaction mode' x6, 'DbHandler: Session terminated by server while checked out by a client: (ECHECKOUTTIMEOUT)' x6, and 'No subscribers for pool ... mode: :transaction, user: postgres' x4. Error rows are clustered at 12:29:21-23Z, 12:29:37-41Z, 12:30:03Z and 12:32:04Z. DIFFERENT SIGNATURE FROM PLUTO-742 AND THE 09-18 BURST: postgres_logs has ZERO 'duration:%' slow-statement rows in 11:30-13:00Z (and zero in 09:30-11:30Z), where 742 had 42 and 09-18 had 43. Postgres's own error rows in the window are 93x 'schema pg_pgrst_no_exposed_schemas does not exist' (the PostgREST exposed-schemas noise that PLUTO-736 (a) is about, not connected to pooler starvation) and 1 'canceling statement due to user request'. So the DATABASE WAS NOT SLOW AT STATEMENT LEVEL; the pooler's own DbHandler could not complete AUTHENTICATION to it inside 15s, and everything downstream (checkout timeout, banner query failing, /api/health hang) follows from that. I could not read pg_stat_activity to say what held connections: my own three mcp execute_sql calls at ~12:33Z died with 'Connection terminated due to connection timeout', which is itself a fourth confirmation that the pooler path was down for a second client at that moment. NOT ESTABLISHED: whether this is the same cause as 09-17/18 (that evidence expired, 1-day retention) or as 742. 742 and 09-18 are DB-slow-with-pooler-victim; this one has no DB-slow signal at all, so 'one recurring instance-slowness' is NOT supported by today's data and a shared-cause claim would be wrong. NEXT READ that would separate them: pg_stat_activity connection count vs the plan's max_connections while it is happening, and whether the pooler's auth query is what is stalling; both need a working connection or the dashboard.
• wi-cli-venus note · 3w ago
  RELAY ARMED 2026-09-19 12:35Z, approved by coder-pluto-cc as this item's lane. On any pluto applog carrying ECHECKOUTTIMEOUT or system/systemBannerQueryFailed, support-evolutiva-cc DMs db-pluto-cc the timestamp and event id ONLY - no triage, no hypothesis - and db-pluto-cc reads same-minute pg_stat_activity (state, wait_event, xact/query age, application_name/usename, counts by state) plus postgres_logs for that window, read-only, posting the raw result here via coder-pluto-cc. support-evolutiva-cc is the trigger because it is the applog DM recipient; that is how the 12:30Z event reached anyone at all, 2 minutes before any probe. Recorded as a standing duty in this agent's memory so it survives a context compaction. SECOND CORRECTION, from coder-pluto-cc and accepted: 'fired in three windows' was also too strong. The ECHECKOUTTIMEOUT text is confirmed on exactly ONE event, 12:30Z. The 09-17/18 rows carry no error text at all, so what has recurred across three windows is the systemBannerQueryFailed SIGNATURE, not a proven identical error. Both of today's overclaims on this item are the same mistake - treating a label as a measurement - which is worth recording precisely because the item already warns against it in the digest paragraph.
• wi-cli-venus note · 3w ago
  SECOND EVENT IN THE 12:30Z BURST, and a measured limit on the relay armed minutes earlier. A second ECHECKOUTTIMEOUT, id 8e1d16f9-eba3-46a5-a5d6-bfcbac5be893, fired @2026-09-19T12:30:11.840Z - five seconds BEFORE the relayed one (9dcafe5d, 12:30:16.721Z) and a distinct id. It reached support-evolutiva-cc's inbox at 12:41Z flagged '1 suppressed alert(s) for route __no_route__': the emitter deduped it by route and flushed it ELEVEN MINUTES late. So the 12:30Z event was at least two checkout timeouts, not one. No pg_stat_activity read was triggered for it - by arrival time the window was gone and a read would have measured nothing. MEASURED PROPERTY OF THE EVIDENCE PATH: applog is real-time for the FIRST event of a signature and up to ~11 minutes late for suppressed duplicates. A burst is precisely when suppression engages, so the relay is single-shot PER BURST, not per event. It worked today and it will keep working for event 1 of any recurrence; it cannot catch events 2..n. Every relay DM from support-evolutiva-cc will therefore quote the applog timestamp, and the receiving lane must check that against its own clock rather than treating arrival as live. Whether the suppression window is tunable is a question for bin-venus-cc as the scrp-* owner; support-evolutiva-cc is not raising it unilaterally since this is coder-pluto-cc's incident. Both events carry route __no_route__ and no digest, consistent with the 09-17/18 systemBannerQueryFailed rows.
• wi-cli-venus note · 3w ago
  Second ECHECKOUTTIMEOUT same burst: id 8e1d16f9-eba3-46a5-a5d6-bfcbac5be893 at 12:30:11.840Z, 5 s BEFORE 9dcafe5d (12:30:16.721Z), route __no_route__, no digest. Reached support 11 min late as '1 suppressed alert(s)': the applog emitter dedupes by route. Consequences: (a) >=2 checkout timeouts in the 12:30 burst, not 1; (b) the relay arranged for pg_stat_activity catch-in-the-act is real-time for the FIRST event of a burst only, later duplicates arrive up to ~11 min stale and their window is gone; relays must carry the applog timestamp and readers check it against their own clock. Emitter is a scrp-* script, not my lane; asked bin-venus-cc whether the suppression window is tunable.
• wi-cli-venus commented · 3w ago
  MEASURED LIMIT ON THIS ROW'S ONLY EVIDENCE PATH (relayed by support-evolutiva-cc, db-pluto-cc recording): a second ECHECKOUTTIMEOUT, event id 8e1d16f9-eba3-46a5-a5d6-bfcbac5be893, applog timestamp 2026-09-19T12:30:11.840Z, five seconds BEFORE the relayed 9dcafe5d-be4b-4c4f-a42f-e4aa318516a5 (12:30:16.721Z), reached the recipient at 12:41Z flagged '1 suppressed alert(s) for route __no_route__'. So the 12:30Z burst held AT LEAST TWO checkout timeouts, and the applog emitter dedupes by route and flushes duplicates up to ~11 minutes late. Consequence: the catch-in-the-act relay (pg_stat_activity read on a timestamp DM) works for the FIRST event of a burst and is useless for suppressed ones; every relay must carry the applog timestamp and be checked against the clock before any live read is trusted. The suppression window is in a scrp-* emitter (bin-venus-cc's lane, not db-pluto-cc's or support's); raising or bypassing it for this signature is a question for that maintainer, and coder-pluto-cc owns whether to ask it. No pg_stat_activity read was taken for the 8e1d16f9 event because its window closed 11 minutes earlier.
• wi-cli-venus note · 3w ago
  POOLER-SIDE, now with two independent clients (relayed by support-evolutiva-cc, verified by me against postgres_logs). (1) 12:30Z: app, Vercel, TRANSACTION mode, ECHECKOUTTIMEOUT 15000ms x2 (12:30:11.840Z, 12:30:16.721Z). (2) 12:49:42Z: applog-listen@pluto on venus, SESSION mode, FATAL 'TERRA-25 preflight could not read the catalog ... ECHECKOUTTIMEOUT ... 15000ms in Session mode'; systemd restarted it 12:49:47Z. Different host, different client, different connection mode, same 15 s checkout failure. CONTROL (support): mars, terra, enamel, venus listeners on the same host 24h = zero ECHECKOUTTIMEOUT, so not the venus box or shared lib: it is pluto's pooler/tenant. MY CHECK: postgres_logs 12:20Z-12:50Z filtered to exclude the flat pg_pgrst line, cron-10 drain and checkpoints returns ZERO rows - Postgres itself logged NOTHING (no slow statement, no timeout, no FATAL, no too-many-connections) across both events. So the failure is upstream of Postgres, in Supavisor's checkout, on a healthy DB. This kills the DB-slowness reading for THIS signature and does not extend to the 09-11/09-18 episodes, which DID log slow statements: two different mechanisms on one free-tier instance. Cannot be fixed from src/. Monitoring plane: applog-listen dies in the same failure (its own catalog preflight needs a pooler connection) - a control that vanishes when needed; its 900 s failnotify cooldown suppressed >=1 earlier failure since 00:34Z (journal rotated, unverified). Not determined: WHY Supavisor refuses (tenant pool_size/max_client_conn on the free plan is not settable via Management API - measured earlier). Evidence for eq#112 ASK 2; adding there.
• wi-cli-venus note · 3w ago
  THREE UNRELATED CLIENTS, THREE FAILURE MODES, ONE POOLER - support-evolutiva-cc, 2026-09-19 12:30-12:50Z. This is the first evidence on this item that points pooler-side by MEASUREMENT rather than by reading a mechanism out of an error string. 12:30:11.840Z and 12:30:16.721Z: the Vercel app, Transaction mode, ECHECKOUTTIMEOUT after 15000ms, two distinct ids (9dcafe5d, 8e1d16f9). 12:49:42Z: applog-listen@pluto.service, a venus-local Node listener sharing no code and no host with the app, SESSION mode, same ECHECKOUTTIMEOUT after 15000ms, FATAL XX000, refusing to start at its TERRA-25 tenancy preflight; systemd restarted it, active again 12:49:47Z, NRestarts=1, cursor 12:44:33.591Z. 12:50:16Z: applog-pull@pluto.service, also venus-local, different failure mode - EAUTHQUERY 'auth_query secret check timed out' - and it did NOT self-recover; unit state failed. CONTROL that rules out the venus host and the shared script: the other four tenants' listeners on the same box (mars, terra, enamel, venus) show ZERO ECHECKOUTTIMEOUT over 24h. So two connection modes plus an auth_query timeout, three unrelated consumers, all against pluto's pooler specifically. SECOND-ORDER FINDING, which matters for how this item gets evidence at all: the monitoring plane fails from the very cause it exists to report. When pluto's pooler saturates, the relay armed at 12:35Z dies with it, and with applog-pull failed the listen leg is the only remaining path - pluto error reporting is currently single-point and that point has already crashed once today from this cause. A control that disappears exactly when it is needed is not a control. Raised to bin-venus-cc as the unit owner (applog-pull@pluto needs a restart and is not self-healing); no unit touched by support-evolutiva-cc. Also unresolved: scrp-applog-failnotify-pluto reports a further listen-leg failure suppressed by a 900s cooldown since 00:34Z, which was not in the journal window read - possibly rotated, worth a look by whoever holds the retention.
• wi-cli-venus commented · 3w ago
  RAW RESULT for the 12:49:42Z Session-mode failure (applog-listen@pluto, TERRA-25 preflight ECHECKOUTTIMEOUT, relayed by support-evolutiva-cc). Read at 2026-09-19T12:50:31Z, 49s after the event, so the window was still open. pg_stat_activity (current database), 13 backends TOTAL: active postgres 1 (my own query), active applog_reader 1, idle applog_reader 1 (0.15s in state), idle authenticator 1 (1m59s) and 1 (21 days 21h, ClientRead), idle pgbouncer 1, idle pm_triage_reader 1 (10s), idle supabase_admin 2 (1h01m, ClientRead), plus 3 background/extension rows with null state. wait_event: NO row waiting on Lock, IO or LWLock; the only waits are Client/ClientRead on idle sessions. No idle-in-transaction session, no xact older than seconds. So at the moment the pooler reported it could not check out a connection, the DATABASE HELD ~13 CONNECTIONS, NONE BLOCKED, NONE LONG-RUNNING: backend connection exhaustion and lock/IO contention are both absent in this snapshot. supavisor_logs 12:40-12:50Z: 'DbHandler: Authentication timeout after 15000ms' x2 and 'ClientHandler: (ECHECKOUTTIMEOUT) unable to check out connection from the pool after 15000ms in Session mode' x1. postgres_logs same window: 0 duration rows, 0 non-LOG severity rows. So for the second time today the pooler's own DbHandler could not complete AUTHENTICATION to a database that logged nothing and showed no load, and this time a client in Session mode on another host hit it too. This supports 'pooler-side, not app-side, not DB load', the open question on this row. It does NOT identify WHY DbHandler authentication stalls (network path pooler->DB, the pooler's own get_auth call, or Supavisor internals): nothing readable from pg_stat_activity or postgres_logs separates those, and a failed get_auth that never reaches the DB would leave exactly this footprint. Whoever can escalate to Supabase support has a concrete artifact set: two clients, two modes, two hosts, 'Authentication timeout after 15000ms' from DbHandler, DB idle. Also on record: a 21-day-old idle authenticator session is normal PostgREST, not a leak.
• wi-cli-venus note · 3w ago
  THIRD CLIENT, 12:50:16Z: applog-pull@pluto (venus) FAILED, not self-restarting: '[applog] fatal: error: (EAUTHQUERY) auth_query secret check timed out' (relayed by support-evolutiva-cc). Three clients / three failure modes vs pluto's pooler in 20 min: app Transaction-mode ECHECKOUTTIMEOUT x2 (12:30), listener Session-mode ECHECKOUTTIMEOUT (12:49, self-restarted), pull auth_query timeout (12:50, still failed). Other four tenants on the host: zero. Pull backstop is DOWN; only the listen leg remains. Unit restart is bin-venus-cc's lane; pinged by support. Postgres logged nothing in the window (see previous note).
• wi-cli-venus commented · 3w ago
  SECOND SNAPSHOT 2026-09-19T12:51:17Z (db-pluto-cc), 61s after applog-pull@pluto failed at 12:50:16Z with 'EAUTHQUERY auth_query secret check timed out'. supavisor_logs 12:47-12:51Z: 'DbHandler: Authentication timeout after 15000ms' x2 and 'ClientHandler: (EAUTHQUERY) auth_query secret check timed out' x1. postgres_logs same window: 0 duration rows and 0 get_auth rows, i.e. the pooler's auth_query never produced a slow or logged statement on the database. pg_stat_activity: 13 backends (9 idle/ClientRead, 2 active, 2 extension), no non-Client wait, none blocked. /api/health 12:51:21Z dbOk true. Same footprint as 12:29-12:33Z and 12:49:42Z: pooler auth path stalls while the database shows no load and logs nothing. Third client, third failure string (EAUTHQUERY), consistent with the Authentication-timeout stall being upstream of every client-visible error. bin-venus-cc restarted the pull leg 12:51:18Z and it recovered; the listen-leg dedup window fix (005d36c, 60000ms for pluto) is source-PASS but the deployed unit is UNVERIFIED (LoadState not-found), so a burst can still be reported up to ~11 min late.
• wi-cli-venus note · 3w ago
  Evidence path repaired (bin-venus-cc, reported not verified by me): APPLOG_DEDUP_WINDOW_MS=60000 live on applog-listen@pluto (user unit, EnvironmentFile /home/rob/.config/applog/%i.env, src 005d36c), restarted 12:50:04Z, catch-up done 12:51:17Z; applog-pull@pluto restarted 12:51:18Z, cursor 12:30:16.721Z. Duplicates within 60 s no longer held ~10 min, so a recurrence relays near-real-time per event. Caveat unchanged: the listener dies in the same pooler failure it reports (12:49:42Z).
• wi-cli-venus commented · 3w ago
  RAW RESULT for the 13:04:52Z systemBannerQueryFailed (event 90c063b3-0991-46ff-97a4-d2238d30083f), read 13:05:49-13:06:11Z (57s-79s after the event). (1) pg_stat_activity: NOT READABLE. mcp__supabase__execute_sql failed 2/2 with "Connection terminated due to connection timeout" at ~13:06Z, same as 12:33-12:36Z (5/5). (2) supavisor_logs 13:04:27-13:04:52Z: 13:04:27 two backends authenticated after "Wait parameter status timeout"; 13:04:41 DbHandler "Authentication timeout after 15000ms" then ECHECKOUTFAILED 08006 "Failed to connect to database: authentication did not complete within 15000ms"; 13:04:42 second "Authentication timeout after 15000ms" + ECHECKOUTTIMEOUT "unable to check out connection from the pool after 15000ms in Transaction mode (XX000)"; 13:04:52 "Pool checkout took over 1s (10380ms)" then Backend authenticated backend_pid 3316287. (3) postgres_logs 13:00-13:06Z, differs from the 12:29-12:51Z window: 3 rows, "cron job 10 job startup timeout" 13:00:36Z, "canceling statement due to statement timeout" 13:01:37Z and 13:03:42Z. No get_auth slow rows, no duration: rows. Not established: which statement was cancelled (message carries no text) and whether cron job 10 is related. Read-only; no writes.
• wi-cli-venus note · 3w ago
  13:04Z/13:06Z RECURRENCE (relayed by support): 90c063b3 13:04:52.892Z 'authentication did not complete within 15000ms'; a4577293 13:06:21Z 'timeout exceeded when trying to connect'; both systemBannerQueryFailed. I read postgres_logs 12:50-13:08Z: UNLIKE 12:20-12:50Z, Postgres NOW logs degradation - statement-timeout cancels at 12:51:59, 12:57:10, 12:58:13, 13:01:37, 13:03:42 (5), user-request cancels 12:54:37 and 13:04:58, 'unexpected EOF on client connection with an open transaction' 12:54:37 (hm: 12:54:37 is the EOF; cancels at 13:04:58), and a 14399 ms INSERT at 12:52:06. REVISES my earlier pooler-only reading: sequence is pooler failures FIRST (12:30, 12:49, silent Postgres), DB-side degradation from ~12:52 onward, and it is still running at 13:05. So this is a live episode (call it episode 3 of 742's class) whose leading edge looked pooler-only. I do not claim the pooler failures CAUSED the DB degradation or vice versa - only that Postgres was quiet 12:20-12:50 and not after. Error texts differ (checkout / auth-phase / connect): three phases of connection establishment, consistent with connection establishment being the slow step - not proven. Same instance-level conclusion as 742: nothing in src/. Still ASK 2 on eq#112.
• wi-cli-venus commented · 3w ago
  RAW RESULT for the 13:06:21Z systemBannerQueryFailed "timeout exceeded when trying to connect" (event a4577293-6e73-4244-8534-eca5213864f0), read 13:08:29-13:08:53Z = 2m08s+ after the event, so the live window was already closed; treat as log evidence only. (1) pg_stat_activity: NOT READABLE, execute_sql failed with "Connection terminated due to connection timeout" (3rd consecutive read failure this hour, 13:06 and 13:08Z). (2) supavisor_logs 13:04:52-13:08:19Z: 13:06:15Z clients connected/terminated; 13:06:29Z "Pool checkout took over 1s (13905ms)" then Backend authenticated backend_pid 3316313 (prior event: 10380ms, pid 3316287); no Authentication timeout line in this window; 13:06:39Z client Terminate. (3) postgres_logs 13:04:52-13:08:53Z: one row, "canceling statement due to user request" 13:04:58Z; no slow, get_auth or duration: rows. Note: checkout of 10-14s with a backend that authenticates afterwards fits the same pooler-side stall as 12:29Z; cause still not identified. Read-only.
• wi-cli-venus note · 3w ago
  CORRECTION to the note above (I mis-mapped timestamps): postgres_logs 12:50-13:08Z = statement-timeout cancels x4 at 12:51:59, 12:58:13, 13:01:37, 13:03:42; INSERT duration 14399 ms at 12:52:06; 'unexpected EOF on client connection with an open transaction' at 12:54:37; user-request cancels x2 at 12:57:10 and 13:04:58. Conclusions unchanged: Postgres quiet 12:20-12:50Z, degraded from 12:51:59, still degraded at 13:05.
• wi-cli-venus commented · 3w ago
  RAW RESULT, third relay (venus applog-pull@pluto ECHECKOUTTIMEOUT Session mode, 13:20:23Z), read 13:21:04Z = 41s after. (1) pg_stat_activity: NOT READABLE, execute_sql "Connection terminated due to connection timeout" (4th consecutive failure since 12:33Z). (2) supavisor_logs 13:17-13:20Z: 13:20:23Z two Session-mode ECHECKOUTTIMEOUT (15000ms) each followed by DbHandler "Authentication timeout after 15000ms" (the venus client, matches the reported failure to the second). Earlier in the same window, Transaction-mode pool for tenant fdwjmzjwurbpkxersigg user postgres: 13:17:35Z "Starting pool(s)"; 13:17:50Z Authentication timeout 15000ms + ECHECKOUTFAILED 08006; 13:18:07Z Transaction-mode ECHECKOUTTIMEOUT; 13:18:23Z backend authenticated pid 3316425; 13:20:07Z "No subscribers ... shutting down gracefully" for that Transaction pool. So the Transaction pool was created cold at 13:17:35Z (after going idle) and its first backend authentications hit the 15000ms limit. (3) postgres_logs 13:17-13:21Z: zero rows. Established: 4 Supavisor-side auth timeouts in 3 minutes with zero postgres_logs rows = the DB logged nothing while the pooler could not authenticate. Not established: why the pooler-to-DB auth leg stalls. Read-only.
• wi-cli-venus priorityChanged · 3w ago
  1
• wi-cli-venus assigned · 3w ago
  coder-pluto-cc
• wi-cli-venus note · 3w ago
  SEVERITY RAISED p2 -> p1: user-facing availability defect, live. support-evolutiva-cc probes of /api/health (v2.23.96) 13:21-13:22Z: 2 of 5 dbOk:false at 10-15.5 s (the 15 s pool timeout), /login 17.5 s. applog-pull@pluto also failed 12:50:16Z and 13:20:23Z while the four sibling tenants on the same host stayed clean. Flapping, not down. No src/ change can fix an instance/pooler-side failure; the only levers are on the Supabase dashboard (compute/pooler settings, project restart) = Elazar's hands, filed as eq. Mitigation NOT taken by me: none exists in app code that I can justify on this evidence.
• wi-cli-venus commented · 3w ago
  RAW RESULT, escalation relay (support health probes 13:21:25Z dbOk:false 15.5s, 13:22:00Z dbOk:false 10.3s), read 13:22:40-13:23:10Z, live and flapping. (1) My own /api/health probe 13:22:41Z: 200, 0.26s, dbOk:true. (2) pg_stat_activity: NOT READABLE, execute_sql "Connection terminated due to connection timeout" at ~13:23Z (5th consecutive failure since 12:33Z); the app pooler path and the MCP path both fail while the same pooler authenticates other clients seconds apart. (3) supavisor_logs 13:21:42-13:22:33Z: 13:21:42Z Transaction ECHECKOUTTIMEOUT 15000ms; 13:21:43Z Authentication timeout 15000ms + ECHECKOUTFAILED 08006; 13:22:00Z Authentication timeout 15000ms + ECHECKOUTFAILED 08006 (matches the 13:22:00Z dbOk:false probe); 13:22:04-13:22:12Z backends authenticate normally (pids 3316455, 1396278937, 1396280660) = the flap back to dbOk:true; 13:22:33Z clients terminate. (4) postgres_logs 13:18-13:23Z: ZERO rows. So in the failing windows Postgres logs nothing and the pooler authentication leg times out at exactly 15000ms; in the good windows authentication completes in about 1s. Cause of the stall not identified; the evidence set (three clients, both modes, four other tenants clean, zero postgres_logs rows, pg_stat_activity unreadable from the MCP path) is what a Supabase support ticket needs. Read-only.
• wi-cli-venus note · 3w ago
  Impact sample 13:39Z (support): /api/health 3 probes, 1 fails at 15.48 s (dbOk false), next two 0.44/0.35 s. Same 1-in-3 shape as 13:21Z; held ~17 min across two samples. Six events today 12:30-13:38Z, three clients, both pooler modes. Grant-immediately-or-time-out-at-15s is consistent with a stuck subset of pooled backends rather than uniform slowness - description of the shape, cause still undetermined. Awaiting Elazar on eq#116 (dashboard graphs / restart).
• wi-cli-venus commented · 3w ago
  RAW RESULT, 13:37:55Z relay (event 7ca76bb4-ccc7-4f65-8e6f-8a29d76cac90, Transaction ECHECKOUTTIMEOUT), read 13:38:56-13:39:10Z = 61s after, window just open. (1) /api/health 13:38:56Z: 200, 0.72s, dbOk:true. (2) pg_stat_activity: NOT READABLE, execute_sql "Connection terminated due to connection timeout" (6th consecutive failure since 12:33Z). (3) supavisor_logs 13:37:27-13:39:04Z, a continuous stall: 13:37:27Z two Authentication timeout 15000ms + two Transaction ECHECKOUTTIMEOUT; 13:37:41-42Z three more ECHECKOUTTIMEOUT; 13:37:43-44Z two Authentication timeout + two ECHECKOUTFAILED 08006; 13:37:48Z another pair; 13:37:55Z pool checkout took 6890ms then authenticated; 13:38:04-05Z checkouts took 3177ms and 4035ms; 13:38:15Z-13:38:49Z auth completes normally; 13:39:04Z a further Authentication timeout 15000ms + Transaction ECHECKOUTTIMEOUT while the 13:38:56Z health probe was dbOk:true. About 12 Supavisor-side 15000ms auth/checkout failures in 100s, then partial recovery through 4-7s checkouts. (4) postgres_logs 13:34-13:39Z: ZERO rows. Read-only.
• wi-cli-venus commented · 3w ago
  CORRECTION to the 13:37:55Z RAW RESULT above: the 13:39:04Z Authentication timeout + ECHECKOUTTIMEOUT I cited as occurring during my 13:38:56Z probe was support-evolutiva-cc /api/health probe (dbOk:false 15.48s at 13:39:04.841Z), so it is probe-induced, not an independent user-facing event; event a1a56357-a184-48ec-a2fa-86c840a9c9d0 (13:39:07Z) is the same probe. The clean series is 12:30Z, 12:50:16Z, 13:04:52Z, 13:06:21Z, 13:20:23Z, 13:37:55Z. Independent of that: the failing draw costs the 15000ms limit and the next draw is sub-second (probes 13:39:04.8Z fail, 13:39:05.3Z and 13:39:05.7Z ok), and the 13:37:27-13:37:48Z stall in supavisor_logs was user-driven, before any probe. Support has stopped probing.
• wi-cli-venus note · 3w ago
  13:51Z: applog-pull@pluto (venus, Session mode) 4 consecutive 15 s ECHECKOUTTIMEOUTs 13:50:23-13:51:21Z (relayed by support). Contemporaneous prod health from me, 3 probes 13:51:45-13:51:51Z: dbOk true x3, 1.12 / 1.03 / 0.36 s. So the app's Transaction-mode path GRANTED while the venus Session-mode client was refused 4x: the failure is not uniform across the pooler - Session-mode checkout from venus is refused while Transaction-mode from Vercel succeeds, in the same minute. Hypothesis, untested: Session-mode pool for the tenant is exhausted/stuck separately from the Transaction pool. Needs pg_stat_activity/Supavisor (db-pluto-cc window open now) to test. Prod users not currently hit; the log plane (listen/pull) is.
• wi-cli-venus commented · 3w ago
  RAW RESULT, sustained Session-mode failures (venus applog-pull@pluto, 4 consecutive 15000ms ECHECKOUTTIMEOUT), read 13:51:47-13:52:10Z, live. (1) /api/health 13:51:48Z: 200, 0.53s, dbOk:true, i.e. the Transaction path granted while the Session path was refusing. (2) pg_stat_activity: NOT READABLE, execute_sql "Connection terminated due to connection timeout" (7th consecutive failure since 12:33Z). (3) supavisor_logs 13:50:08-13:51:45Z: Session-mode ECHECKOUTTIMEOUT + DbHandler "Authentication timeout after 15000ms" at 13:50:23Z, 13:50:45Z, 13:51:06Z and two at 13:51:28Z, each preceded ~15s earlier by "ClientHandler: Connection authenticated" (the client-to-pooler handshake succeeds instantly; it is the pooler-to-Postgres backend authentication that never completes in 15000ms). 13:51:34Z: two backends authenticated (pids 1396808259, 3316696) = recovery. Total refusal run about 71s (13:50:08-13:51:34Z). (4) postgres_logs 13:47-13:52Z: ZERO rows. Two separate pooler pools (Session and Transaction) were in different states at the same second, so the fault is not a single stuck backend or a Postgres-wide condition; it is per-backend-connection authentication from Supavisor to Postgres. Read-only.
• wi-cli-venus commented · 3w ago
  RAW RESULT, 14:41:03Z relay (event 1dab7b3d-c36b-48a0-9e0b-dc58675332e4, Transaction ECHECKOUTTIMEOUT), read 14:42:04-14:42:30Z = 61s after. (1) /api/health 14:42:06Z: 200, 2.17s, dbOk:true (slow draw, not failed). (2) pg_stat_activity: NOT READABLE, execute_sql "Connection terminated due to connection timeout" (8th consecutive failure since 12:33Z). (3) supavisor_logs 14:40:44-14:41:03Z: 14:40:44Z four clients connect; 14:40:45Z two backends authenticate after "Wait parameter status timeout" (~1s); 14:40:58Z Authentication timeout 15000ms + ECHECKOUTFAILED 08006; 14:40:59Z Authentication timeout + Transaction ECHECKOUTTIMEOUT (15s after the 14:40:44Z connects); 14:41:00Z two more Authentication timeout + two Transaction ECHECKOUTTIMEOUT; 14:41:03Z backends authenticate (pids 3317129, 3317130), pool checkout took 3277ms and 1549ms = recovery. Episode about 14:40:43-14:41:03Z, ~20s, self-cleared; same shape as 13:37Z: some backend authentications in a batch complete in ~1s, others never complete inside 15000ms, and the ones that never complete are refused as a group. (4) postgres_logs 14:38-14:42Z: ZERO rows. Support boundary check for the 13:50-13:52Z episode against my 13:51Z read: consistent (last failure 13:51:28Z, two backends authenticated 13:51:34Z). Read-only.
• wi-cli-venus commented · 3w ago
  RULING on the two strings (support relayed 1033fdc3-5751-411c-8e4a-5f91690ea59a "authentication did not complete within 15000ms" 14:41:03.138Z and 1dab7b3d "ECHECKOUTTIMEOUT ... Transaction mode" 14:41:03.466Z, 328ms apart): supavisor_logs emits BOTH strings itself in the same second for the same backend-auth stall. 14:40:58Z ECHECKOUTFAILED 08006 "Failed to connect to database: authentication did not complete within 15000ms" and 14:40:59-14:41:00Z ECHECKOUTTIMEOUT "unable to check out connection from the pool after 15000ms in Transaction mode", each next to a DbHandler "Authentication timeout after 15000ms"; same pairing at 13:17:50Z/13:18:07Z, 13:21:43Z/13:21:42Z and 13:37:43-44Z/13:37:48Z. So they are two surfaces of one pooler event (one waiter gets 08006 when the backend connect itself fails, the others queue on that same connect and get ECHECKOUTTIMEOUT), and "timeout exceeded when trying to connect" is the app pg-pool side of the same wait. That is the same defect, not a request-id join; the request-id join is not available from supavisor_logs. It says nothing about why the backend auth does not complete.
• wi-cli-venus commented · 3w ago
  RAW RESULT, second episode (venus applog-pull@pluto Session ECHECKOUTTIMEOUT onset 14:50:21Z), read 14:50:49-14:51:15Z = 28s after. (1) /api/health 14:50:51Z: 200, 1.97s, dbOk:true (slow draw). (2) pg_stat_activity: NOT READABLE, execute_sql "Connection terminated due to connection timeout" (9th consecutive failure since 12:33Z). (3) supavisor_logs 14:48:34-14:50:49Z: the episode started on the APP (Transaction) side before the venus pull saw it: 14:48:34Z clients connect, one backend authenticates; 14:48:49Z Authentication timeout 15000ms + Transaction ECHECKOUTTIMEOUT (15s after the 14:48:34Z connects); 14:49:04-06Z another Transaction ECHECKOUTTIMEOUT + Authentication timeout; 14:50:15Z another pair; 14:50:21Z two Session-mode ECHECKOUTTIMEOUT + two Authentication timeout (the venus pull, exactly the reported onset); 14:50:30Z another Transaction ECHECKOUTTIMEOUT; 14:50:33Z two backends authenticate (pids 3317217, 1397857923) with pool checkout 5397ms = start of recovery; 14:50:35Z a third authenticates. So Transaction and Session pools failed in the same episode, roughly 14:48:34-14:50:33Z (~2 min), with the auth-timeout cadence a fixed ~15s (14:48:49, 14:49:04, 14:50:15, 14:50:30) = one 15000ms wait per batch of queued clients. (4) postgres_logs 14:46-14:51Z: ZERO rows. Duration and onset now match 13:50-13:52Z (~2 min) and are 60 min apart (13:50:23Z, 14:50:21Z). Read-only.
• wi-cli-venus commented · 3w ago
  RAW RESULT, the HANG in the 14:50Z episode (venus applog-pull@pluto attempt 2, 14:50:26Z-14:52:26Z, killed by systemd TimeoutStartSec=120s), read 14:52:55Z from supavisor_logs. (1) 14:50:27Z two clients authenticate (attempt 2 handshake, instant). 14:50:33-35Z three backends authenticate (pids 3317217, 1397857923, 3317219; one checkout 5397ms). Then NO supavisor row of any kind for the next ~112s: no Authentication timeout, no ECHECKOUTTIMEOUT, no error. (2) 14:52:26Z "ClientHandler: (ECLIENTSOCKETCLOSED) Client socket closed while state was busy (proxy)" + "Terminate received from client" = the pooler still had that client in state BUSY (a granted backend, a query or protocol step in flight) when the venus process was SIGTERMed. So the hang is not a checkout refusal: the client was GRANTED a backend at 14:50:33Z and then waited ~2 min on it. (3) postgres_logs 14:48-14:53Z: ZERO rows, so no statement_timeout cancel, no error and no slow statement on the Postgres side for that granted connection; whatever it was waiting on left no Postgres log. (4) Attempt 3: 14:52:33Z two clients authenticate, 14:52:48Z two Session ECHECKOUTTIMEOUT + two Authentication timeout 15000ms = back to the fast refusal mode while the app Transaction path answers /api/health 200 dbOk:true 2.0s at 14:53:01Z. (5) pg_stat_activity NOT READABLE (execute_sql "Connection terminated due to connection timeout", 10th consecutive failure since 12:33Z). Established: granted-then-silent, backend BUSY on the pooler side, nothing on the Postgres log. Not established: what the query was, whether it reached Postgres at all, or the hold cause. Read-only.
• wi-cli-venus note · 3w ago
  2026-09-19 support relay (source: support-evolutiva-cc 12:19 ART, not my measurement): pooler episode 2 in venus Session mode 14:50:21Z-15:00:50Z (~10.5 min, 12 applog-pull restarts; episode 1 ~2 min, 4 restarts). Modes alternated inside it: fast 15000ms ECHECKOUTTIMEOUT at 14:56:41, 14:59:08, 14:59:29 and 120 s silent hangs killed at 14:52:26, 14:58:46. New app event 15:17:06.089Z id f690fdaf-42b0-466e-9a75-f4716009df6d 'timeout exceeded when trying to connect'. StartLimitBurst never engaged (hangs space failures past 60 s), so my 13:51Z exhaustion note is retracted. Two samples, not a trend. Still needs pg_stat_activity/Supavisor read for the 14:50-15:00Z bracket (db-pluto-cc) and eq#116 (Elazar). No src change indicated.
• wi-cli-venus commented · 3w ago
  RETRACTION + RAW RESULT (2026-09-19 read 15:19-15:21Z). RETRACTION: every "postgres_logs ZERO rows" I posted above for a LIVE read (13:05, 13:08, 13:21, 13:22, 13:38, 13:51, 14:42, 14:50, 14:52Z) was wrong as a statement about the database: postgres_logs is ingested with a lag, and a statement is logged when it FINISHES, so a read seconds after an event is empty by construction. Re-read now, the same windows are NOT empty, and my earlier statement that 12:29-12:51Z was a healthy DB with zero slow rows was also a live-read artifact. The 09-19 events carry the SAME instance-slowness signature as PLUTO-742 and the 09-18 burst. postgres_logs, event time: 12:30:41Z INSERT appEvents 23583ms; 12:30:52Z INSERT appEvents 38031ms; 12:30:53Z "process 3315991 still waiting for AccessExclusiveLock on object 0 of class 1262 of database 0 after 1041ms", acquired 12:31:21Z "after 29092ms" (a lock on class 1262 = pg_database, object 0, held 29s, holder NOT identified); 12:32:32Z SELECT value FROM systemSettings WHERE key=banner 21966ms (Index Scan); 12:34:42Z SELECT * FROM pgbouncer.get_auth 22808ms; 12:45:28Z get_auth applog_reader 16946ms; 13:05:23Z INSERT appEvents 22873ms; 13:08:12Z INSERT appEvents 108046ms; 13:32:38Z get_auth 26484ms; 13:32:53Z 36839ms; 13:39:07Z INSERT appEvents 49773ms; 14:41:30Z 12992ms; 14:43:17Z 20821ms; 14:43:35Z 30134ms. Episode 2 (14:50:21-15:00:50Z): 14:52:13Z and 14:54:49Z statement timeouts; 14:56:38Z SELECT appEvents 11045ms; 14:58:38Z SELECT value FROM systemSettings key=banner 14172ms (Index Scan); 15:00:48Z statement timeout; 15:00:50Z applog pull SELECT 14837ms; supavisor 14:50-15:00Z: ~19 Authentication timeout 15000ms, 3 ECLIENTSOCKETCLOSED while busy (14:52, 14:55, 14:58Z = the 120s hangs, each killed by systemd), one while idle 15:00Z, checkouts 11498ms/6005ms/3987ms, and 15:00Z "DbHandler: Cleanup timeout, shutting down". A one-row indexed lookup taking 14-22s and get_auth taking 17-26s cannot be a pooler-only fault; the pooler auth query (get_auth) is one of the slow statements, same as PLUTO-742. Also recurring in these windows: "cron job 10 job startup timeout" (job 10 = fn_drain_email_outbox_if_due) at 12:50:19Z, 13:00:36Z, 13:31:15Z, 14:46:45Z. Episode 3 live (app events 15:17:06Z, 15:19:25Z, 15:19:49Z): supavisor 15:18:09-15:19:16Z Transaction ECHECKOUTTIMEOUT at 15:18:09, :24, :41, :59 and 15:19:16Z (fixed ~15s cadence), ECHECKOUTFAILED 08006 at 15:18:26, :44, 15:19:01Z. What is still NOT identified: why the instance stalls (the database-level AccessExclusiveLock holder, the disk/CPU budget, or a Supabase-side event); pg_stat_activity is still NOT READABLE from the MCP path. The Supabase support artifact should be built from the postgres_logs rows above, not from the pooler rows. Read-only.
• wi-cli-venus note · 3w ago
  EPISODE 3 live (support relay 12:22 ART): app events 15:17:06.089Z f690fdaf, 15:19:25.055Z 122a7539, 15:19:49.799Z 585d42d4; venus Session-mode ECHECKOUTTIMEOUT 15 s at 15:20:52, 15:21:13, 15:21:35, 15:21:56Z (restart counter 4+). Onsets 13:50Z, 14:50Z, 15:17Z (support: not calling a period). My probe of prod /api/health 15:22:12Z: dbOk false after 15.4 s (version 2.23.96, dpl_Vn74q6Kxqvz8zjATaqxdKgPHywNY), then dbOk true 0.36 s and 0.31 s at 15:22:28Z - prod users are being hit, not only the log plane. Needs pg_stat_activity/Supavisor read NOW (db-pluto-cc) and eq#116 (Elazar).
• wi-cli-venus commented · 3w ago
  RAW RESULT, episode 3 live (app 15:17:06Z/15:19:25Z/15:19:49Z; venus Session 15:20:52Z, 15:21:13Z, 15:21:35Z), read 15:22:16-15:22:40Z. (1) db-pluto-cc /api/health probe 15:22:34Z: 200, 15.37s, dbOk:FALSE (one probe of mine, subtract it from any count; the first failed draw of mine all day). (2) pg_stat_activity NOT READABLE, execute_sql "Connection terminated due to connection timeout" (12th consecutive since 12:33Z). (3) supavisor_logs 15:19:16-15:21:56Z, both pools failing in the same minutes: Transaction-mode ECHECKOUTTIMEOUT at 15:19:16, :34, :51, 15:20:14, :29, 15:21:04, 15:21:56Z (~15s cadence, one per queued waiter cohort); ECHECKOUTFAILED 08006 "authentication did not complete within 15000ms" at 15:19:19, :36, 15:20:49, 15:21:41Z; Session-mode ECHECKOUTTIMEOUT at 15:20:30 (x2), 15:20:52 (x2), 15:21:13, 15:21:35 (x2)Z. Between failures Supavisor keeps authenticating fresh backends (15:19:16, :19, :34, :36, :59, 15:20:14, :18, :25, :37, :38, :47, :49, 15:21:00, :34 x2, :41Z): i.e. the pool is not exhausted and not stuck on one backend; it is opening a new backend connection every few seconds and a large share of them never finish authentication inside 15000ms while others finish in ~1s. About 30 Authentication timeouts in 2m40s. (4) postgres_logs for this window is not yet ingested (ingest lag, see RETRACTION above): the retro read of 15:17-15:23Z must be done after ~15:45Z. Read-only.
• wi-cli-venus commented · 3w ago
  RAW RESULT, FIRST READABLE pg_stat_activity (episode 4, onset 16:20:32Z; read ~16:21:10-16:21:30Z, 40-60s after onset). execute_sql succeeded on the 13th attempt. Query 1 (counts, 16:21:10Z): idle/ClientRead 7 (oldest 22d), active 2 (oldest 23.4s, xact age 23.4s), state NULL 2 (xact age 8.2s), Extension/Extension 1 (pg_net worker). Query 2 (rows, ~10s later): 16 backends; the only active client backend was my own query; NO blocked or lock-waiting client backend; no idle-in-transaction; app connections visible: pgbouncer/Supavisor (auth_query) backend age 15m46s idle running SELECT * FROM pgbouncer.get_auth($1) 2.5s ago, applog_reader/Supavisor age 1m12s, authenticator/postgrest, pm_triage_reader. BACKGROUND PROCESSES, the part that is new: pg_cron launcher (pid 4029) wait_event_type IO, wait_event WalInitWrite, xact_age 56.2s (a transaction open 56s waiting on a WAL segment file creation write); walwriter (pid 4025) wait LWLock WALWrite; archiver wait IPC ArchiveCommand; checkpointer/bgwriter/autovacuum launcher idle (Activity). A 56s wait in WalInitWrite in the pg_cron scheduler plus walwriter blocked on WALWrite is a storage/WAL write stall signature; it fits the slow appEvents INSERTs (23-108s), "cron job 10 job startup timeout" rows and the 29s AccessExclusiveLock, all of which are writes/WAL-adjacent, and it fits PLUTO-708 (disk IO budget alert, gp3 3000 IOPS/125 MiB/s). NOT established: this is one 1-2 sample read of a moving state, not a proof; I could not see whether the stall is the volume, IO burst budget, or the archiver (ArchiveCommand wait). Suggested next reads, all read-only: Management API analytics/endpoints/metrics (Prometheus: node disk io time, wal/archive counters) and config/disk/util during the NEXT episode, plus repeat this exact pg_stat_activity query every ~20s while an episode is open. Read-only.
• wi-cli-venus commented · 3w ago
  EPISODE 5 LIVE (db-pluto-cc, read 2026-09-19T16:50:49-16:51:09Z, onset per support 16:50:18Z). supavisor_logs (Management API, not lagged): 16:50:18 x2, 16:50:40 x2, 16:51:01 x1 pairs of 'DbHandler: Authentication timeout after 15000ms' + 'ClientHandler: (ECHECKOUTTIMEOUT) ... after 15000ms in Session mode'; ~21s cadence. pg_stat_activity: execute_sql failed 2 of 2 ('Connection terminated due to connection timeout'), no sample. postgres_logs NOT read (ingest lag); retro-read of episodes 4 and 5 due after ~17:30Z. CORRECTION relayed by support: episode onsets from the venus pull leg are stamped only at :20/:50 (applog-pull@pluto cadence), so they are lower bounds and NO recurrence period can be derived from them; durations 2/10.5/28/4 min are real and NOT monotonic (my earlier 'lengthening' is withdrawn). Period, if it matters, must come from appEvents or postgres_logs.
• wi-cli-venus commented · 3w ago
  EPISODE 6 LIVE (db-pluto-cc, read 17:12:40-17:12:58Z; support app-side onset 17:11:23.550Z, id 38f56f17-fb27-4351-aee0-e9d6231f1a4d, unquantized). supavisor_logs (not lagged): 17:11:17 Authentication timeout after 15000ms; 17:11:17 (ECHECKOUTFAILED) 08006 'authentication did not complete within 15000ms'; 17:11:17 'Session terminated by server while checked out by a client'; 17:11:23 Pool checkout took over 1s (4707ms); 17:11:35 (2276ms). Pooler auth stall began 17:11:17Z, 6s before the app-side row, i.e. the 15s auth wait started ~17:11:02Z. Nothing after 17:11:35 in the 4-min window: the episode may already be short. pg_stat_activity: execute_sql failed ('Connection terminated due to connection timeout'), no sample. Episode 5 per support: venus onset 16:50:18Z, last failure 17:01:57Z, recovery 17:04:00Z, 19 fast refusals, no hang. postgres_logs not read (ingest lag); retro-read of episodes 4-6 (16:17Z onward) due after ~17:40Z.
• wi-cli-venus commented · 3w ago
  EPISODE 7 LIVE + postgres_logs GAP (db-pluto-cc, read 17:50:50-17:51:45Z). (1) supavisor_logs 17:47:10-17:51:10Z: TRANSACTION-mode failures start no later than 17:49:34Z (ECHECKOUTFAILED 08006 'authentication did not complete within 15000ms' 17:49:34 and 17:49:52; ECHECKOUTTIMEOUT Transaction mode 17:49:35 x2, 17:49:51 x2, 17:49:57, 17:50:08, 17:50:13; 'Session terminated by server while checked out by a client (XX000)' 17:49:35, 17:49:51, 17:50:08), then Session-mode ECHECKOUTTIMEOUT 17:50:24 = support's venus onset. So the app path was failing >=50s before the venus leg stamped it (same quantization support named). (2) pg_stat_activity: execute_sql failed, no sample. (3) postgres_logs retro-read of 16:17-17:47Z returned ZERO rows of ANY kind (unfiltered count(*) = 0 in three 30-min windows 16:17-16:47, 16:47-17:17, 17:17-17:47), while 12:30-13:00Z = 30 rows and 14:30-15:00Z = 24 rows. So this is NOT the lag artifact (retro windows are 25+ min old): postgres_logs holds nothing for at least 16:17-17:47Z. Not yet established whether the log shipper is down for the whole span or only inside episodes; the checks of 15:30-16:17Z and 17:47-17:52Z hit HTTP 429 (rate limit), to be redone. Consequence: episodes 4-6 have no postgres_logs evidence and the Supabase support artifact cannot rest on it for those windows. support's point stands: durations/onsets from the venus leg are lower bounds; periodicity must come from appEvents/postgres_logs, and postgres_logs is empty for this span.
• wi-cli-venus commented · 3w ago
  EPISODE 8 LIVE + postgres_logs STOPPED 15:06:19Z (db-pluto-cc, read 18:11:49-18:12:30Z; support app-side onset 18:10:13.336Z id f26899e0-ebed-4c73-936e-86bd7bcfaaff). (1) postgres_logs: last row of ANY kind is 15:06:19Z (max(timestamp)); count(*) = 5 for 15:00-15:15Z, 0 for 15:15-15:30, 15:30-16:00, 16:00-16:17, 16:17-16:47, 16:47-17:17, 17:17-17:47, 17:47-18:11Z (12:30-13:00Z = 30, 14:30-15:00Z = 24). So the instance has emitted NO postgres log rows reaching Supabase's store for ~3h05m, spanning episodes 3-8. That is not lag. Either the log shipper is stalled or the database logged nothing (a stalled WAL/IO path that cannot write its own log is consistent with the WalInitWrite/WALWrite/ArchiveCommand waits seen 16:21Z; not proven). Cannot distinguish from here; it is a question for Supabase support, together with the 500s from config/disk/util and analytics/endpoints/metrics. (2) supavisor_logs live: 18:10:04, 18:10:18, 18:10:34, 18:10:52 Transaction-mode ECHECKOUTTIMEOUT each with 'Session terminated by server while checked out by a client (XX000)'; 18:10:19 ECHECKOUTFAILED 08006 auth did not complete 15000ms; 18:10:04/19/52 'Authentication timeout after 15000ms'. Cadence ~15s. App onset 18:10:13Z sits inside it; stall started <=18:10:04Z. (3) pg_stat_activity not attempted (execute_sql has failed 5 of 5 in episodes since 16:50Z). (4) support's 'app failures cluster ~7 min after venus recovery' (episodes 5, 7): checkable only from appEvents, which needs execute_sql and is failing while episodes are open; I will run it from a healthy minute (GROUP BY minute, systemBanner/ECHECKOUTTIMEOUT rows, 15:00-18:15Z) and post the raw counts.
• wi-cli-venus commented · 3w ago
  EPISODE 10 LIVE (db-pluto-cc, read 19:08:31-19:08:55Z; support event 19:07:23.438673Z id=498a76de serverError /mi-cursada, user-facing). supavisor_logs 19:03:49-19:08:49Z: Transaction-mode ECHECKOUTTIMEOUT at 19:04:56, 19:05:14, 19:05:29 (each 'Authentication timeout after 15000ms'; 19:05:14 and 19:05:29 with 'Session terminated by server while checked out by a client'), 'Pool checkout took over 1s' 9212ms at 19:05:43 and 5281ms at 19:07:23 (the same second as support's serverError). So 498a76de is NOT a 'post-recovery' stray: the pooler was in the same 15000ms auth-stall from <=19:04:56Z, 10 min after the venus recovery at 18:54:33Z, and the pull leg does not run then. Episode 9 (support, app-side 18:40:36Z-18:43:58Z, 3 of 6 user-facing /mi-cursada serverError) had its pooler stall from the same cause; the fault reaches user routes, not only the banner. Implication for the clustering hypothesis: app events after a 'recovery' are more episodes, so 'recovery' as stamped by the pull leg is not evidence the fault ended. pg_stat_activity/appEvents: execute_sql failed again (Connection terminated due to connection timeout); requestId comparison of f26899e0 vs 3e0f5188 still pending a healthy minute. postgres_logs still last row 15:06:19Z (4h02m silent).
• wi-cli-venus commented · 3w ago
  EPISODE 11 LIVE (db-pluto-cc, read 19:47:37-19:47:56Z; support app-side 19:46:27.036959Z id=2ed3e70f 'authentication did not complete within 15000ms' and 19:46:27.044868Z id=931966fc ECHECKOUTTIMEOUT Transaction). supavisor_logs 19:44:56-19:47:56Z: 19:46:14 DbHandler 'Authentication timeout after 15000ms' + ClientHandler (ECHECKOUTFAILED) 08006 'Failed to connect to database: authentication did not complete within 15000ms'; 19:46:15 and 19:46:16 ECHECKOUTTIMEOUT Transaction mode (each with 'Authentication timeout after 15000ms' and 'Session terminated by server while checked out by a client'); 19:46:27 two 'Pool checkout took over 1s' (11212ms and 9185ms) in the same second as both app rows. So the POOLER ITSELF emits both vocabularies within 2s (auth-string to one client, ECHECKOUTTIMEOUT to the next); the app receiving both strings 7.9ms apart is what that produces, consistent with the 14:41Z ruling (two surfaces of one backend-auth stall). It does not settle whether the two app rows are one checkout or two; requestId comparison still pending a healthy execute_sql minute (failed again now). Episode 10 per support: app onset <=19:07:23Z, venus 19:20:30-19:30:43Z, recovery >=19:32:07Z, span >=24m44s. postgres_logs still silent since 15:06:19Z.
• wi-cli-venus commented · 3w ago
  EPISODE 12 LIVE / 'RECOVERY' CHALLENGED (db-pluto-cc, read 19:58:52-19:59:15Z; support app event 19:57:46.813511Z id=df67f1ec ECHECKOUTTIMEOUT, 3m47s after the venus recovery stamp 19:53:59Z). supavisor_logs 19:55:15-19:59:15Z: Transaction-mode ECHECKOUTTIMEOUT, each with 'Authentication timeout after 15000ms', at 19:57:46, 19:58:17, 19:58:32/34, 19:58:51/52, 19:59:11 = a failure every ~15-20s, still running at read time. No failure rows 19:55:15-19:57:45 (2.5 min gap) then it resumes. So the 12m50s / 3m47s 'post-recovery' intervals support has are not clustering: the Transaction pool keeps failing on its own schedule while the Session pool (the only thing the venus leg tests) was quiet; a venus recovery stamp is not evidence the fault ended. Third string 'timeout exceeded when trying to connect' (19:48:11 id=4e604aae): app pg-pool side, the app's own connect timeout firing while the pooler auth wait is in progress; the three strings inside 105s are the pooler's two (ECHECKOUTFAILED-auth, ECHECKOUTTIMEOUT, same second) plus the client library's own timer, one stall, three surfaces (mechanism of the stall itself still unexplained). execute_sql failed again; requestId comparison and appEvents per-minute counts still pending. postgres_logs silent since 15:06:19Z (4h53m).
• wi-cli-venus commented · 3w ago
  FIRST HEALTHY execute_sql (db-pluto-cc, 21:17:21Z, 23s after support's 21:16:58Z event) + appEvents READ. (1) pg_stat_activity 21:17:21Z: NO wait stall: archiver ArchiverMain, checkpointer CheckpointerMain, walwriter WalWriterMain, pg_cron launcher Extension (the 16:21Z WalInitWrite/WALWrite/ArchiveCommand waits are gone); 2 client backends active 39ms (fn_getInformesBundle, a studentFacts CTE) with no wait event. So the DB was answering at 21:17Z. supavisor_logs at the same time: only 'Pool checkout took over 1s' 3360/3552/3866ms at 21:16:49-57, ZERO 'Authentication timeout' lines in 20:05-21:17Z (count 0). support's ~69 min quiet gap is real at the pooler for auth timeouts; the 21:16:58/59 serverErrors (/practicas, /informes RSC, user silviaetoranzo, iPhone, 'timeout exceeded when trying to connect', 1.4s apart) coincide with slow checkouts (3-4s) not with the 15000ms auth stall, i.e. a different, milder shape. (2) f26899e0 vs 3e0f5188 (18:10:13.336673 / .336669Z): both systemBannerQueryFailed, route NULL, requestId NULL, identical errorMessage AND identical errorStack: NOTHING in the rows separates one failure written twice from two concurrent banner calls. Counter-fact: 2ed3e70f / 931966fc (19:46:27.0370 / .0449Z) carry DIFFERENT errorMessage (auth-did-not-complete vs ECHECKOUTTIMEOUT), so that pair IS two separate failing calls; two concurrent banner queries per render exist, which makes the 18:10 pair two calls without a proof. Support's counts of banner rows are therefore not double-logging but are inflated relative to 'events' by the two-call-per-render shape. (3) appEvents timeout-class rows per 10-min UTC bucket since 15:00Z (n/serverError/banner): 15:10 3/0/3; 17:10 1/0/1; 18:10 3/0/3; 18:40 6/3/3; 19:00 1/1/0; 19:10 1/1/0; 19:40 3/0/3; 19:50 4/0/4; 20:00 1/0/1; 21:10 3/3/0. No rows at all 15:20-17:10Z, 17:20-18:10Z, 18:20-18:40Z, 20:10-21:10Z. Cannot be read as 'no failures': supavisor showed Transaction-mode failures at 19:04-19:07Z etc. and the app logger is itself a pool consumer (silence during a stall is expected). Post-recovery clustering: no support in these counts (bursts at 15:10, 17:10, 18:10, 18:40, 19:40-20:00, 21:10 are not spaced by recoveries, and venus 'recoveries' do not bound the Transaction pool). Caveat: applog dedup by route flushes late, so per-minute shape is a lower bound.
• wi-cli-venus commented · 3w ago
  2026-09-20 LIVE (db-pluto-cc, read 12:31:04-12:31:40Z; support event 12:29:31.398Z id=dfa92dc1-8de1-41b4-b02c-f785729a5892 ECHECKOUTTIMEOUT Transaction mode, systemBannerQueryFailed). supavisor_logs 12:26:04-12:31:04Z: 12:28:49 ECHECKOUTFAILED 08006 auth did not complete 15000ms; 12:29:05 ECHECKOUTTIMEOUT Transaction; 12:29:06 ECHECKOUTFAILED 08006 again; 12:29:16 and 12:29:22 ECHECKOUTTIMEOUT Transaction (each with Authentication timeout 15000ms + 'Session terminated by server while checked out'); 12:29:31 Pool checkout took over 1s (14253ms). Cadence ~6-17s, nothing logged after 12:29:31 at read time. pg_stat_activity: execute_sql failed 2 of 2. postgres_logs EMITTING AGAIN: rows present through 12:25:04Z (pg_pgrst_no_exposed_schemas errors every ~33s, cron job 10 fn_drain_email_outbox_if_due starting/completed 12:15/12:20/12:25, all fast) so the 15:06:19Z 09-19 silence has ended (end time not located). Retro-read of the 12:28-12:32Z window for slow statements due after ~12:58Z; NOT read live (ingest lag).
• wi-cli-venus commented · 3w ago
  2026-09-20 12:34:40Z USER-FACING (db-pluto-cc, read 12:35:22Z; support id 13a60e2f-3d23-4338-b459-c55d0fed6629 /mi-cursada serverError 'timeout exceeded when trying to connect'). supavisor_logs 12:26:22-12:35:22Z: stall lines 12:28:49-12:29:31 (already posted), then 12:33:20 x2 ECHECKOUTTIMEOUT Transaction + auth timeout, 12:33:35 ECHECKOUTTIMEOUT Transaction, 12:33:38 auth timeout. NOTHING logged 12:33:39-12:35:22 (no auth timeout, no 'Pool checkout took over 1s'). So the 12:34:40 page error has NO matching pooler line in +-60s: the pooler did not record a stall at that second, 62s after its last failure. 'timeout exceeded when trying to connect' is the app pg-pool connect timer; it fired for a connect the pooler did not log as failing. Not adjudicable further from supavisor_logs alone; postgres_logs retro-read of 12:28-12:36Z due after ~12:58Z. Facts: 4 stall clusters seen this morning by supavisor (12:28:49-12:29:31, 12:33:20-12:33:38) vs 3 app rows (dfa92dc1 12:29:31, 13a60e2f 12:34:40).
• wi-cli-venus commented · 3w ago
  2026-09-20 EAUTHQUERY LIVE (read 12:51:01Z, event 12:50:10Z, age 51s, per support-evolutiva-cc, applog-pull@pluto exit 1). supavisor_logs 12:31-12:51Z RAW: 12:50:10Z ClientHandler (EAUTHQUERY) auth_query secret check timed out; 12:50:57Z DbHandler Authentication timeout after 15000ms + ClientHandler (ECHECKOUTTIMEOUT) 15000ms in Session mode; 12:48:32Z x2, 12:48:47Z (Transaction mode, Session terminated by server while checked out), 12:48:49Z; 12:40:55-12:41:14Z cluster (Transaction mode, Authentication timeout x4, Session terminated x2). execute_sql at 12:51Z: 'Connection terminated due to connection timeout' (pg_stat_activity unreadable, evidence). Ruling: EAUTHQUERY is a 4th pooler-emitted string on the same backend-auth stall (auth_query = pooler querying the DB for the credential), so the stall sits before checkout, consistent with the auth-timeout reading; it does not say WHY. Support's 'single isolated failure today' is a venus-leg (Session pool) fact only: the Transaction pool failed at 12:40:55, 12:41:10-14, 12:48:32-49 with no venus failure. postgres_logs retro-read of 12:40-12:52Z due after ~13:15Z.
• wi-cli-venus note · 3w ago
  2026-09-20 recurrence on the SESSION leg (applog-pull@pluto.service, venus, journalctl --user, all UTC). Relayed live to db-pluto-cc at 13:20:3xZ, ~15s after the last event. 12:50:10 EAUTHQUERY auth_query secret check timed out 12:50:57 ECHECKOUTTIMEOUT after 15000ms in Session mode 12:51:44 ECHECKOUTTIMEOUT after 15000ms in Session mode 12:52:14 systemd StartLimit hit ('Start request repeated too quickly', restart counter 3) - unit stopped retrying 13:20:21 ECHECKOUTTIMEOUT after 15000ms in Session mode SCOPE: Session leg only. Nothing here is evidence about the Transaction pool either way. TWO INSTRUMENT ARTEFACTS, so these numbers are not read as fault properties: (1) applog-pull@pluto.timer fires every 30 min at :20 and :50 (verified from list-timers). 09-19 failed at 12:50:16 and 13:20:23; 09-20 at 12:50:10 and 13:20:21. That is not a daily 30-minute rhythm - those are the only moments the instrument looks. No onset, period or gap can be taken from this unit. (2) systemd restarts the unit ~30s apart on failure and each retry prints its own fatal line, so one bad window emits three or four errors (09-19 13:50:23/13:50:45/13:51:06/13:51:28 is ONE episode). It then gives up at restart counter 3. The 28 quiet minutes after 12:52:14 today are absence of ATTEMPTS, not absence of fault. Consequence worth acting on: on 09-19 13:50 the retries were allowed to run and the unit RECOVERED unaided within ~2 min (Finished 13:52:14). Today the start limit cut that off. So hitting StartLimit is itself a degradation - it removes the self-recovery path - independent of whatever is wrong at the pooler. Also: the failnotify alert for the 13:20 failure says the cooldown window 'lapsed with no further failures, so THIS failure is isolated from them, not part of a burst'. True of the WINDOW, misleading about the FAULT - 12:50-12:51 and 13:20 are the same three-string shape 29 min apart.
• wi-cli-venus commented · 3w ago
  2026-09-20 13:20Z SESSION-LEG LIVE (read 13:20:56Z, event 13:20:21Z, age 35s, per support-evolutiva-cc). supavisor_logs 13:00-13:21Z RAW: 13:20:21Z Authentication timeout 15000ms x2 + ECHECKOUTTIMEOUT Session mode x2; Transaction-mode clusters NOT visible to venus: 13:14:44-13:15:37Z (ECHECKOUTFAILED 08006 auth did not complete, ECHECKOUTTIMEOUT Transaction 13:14:59, Authentication timeout 13:15:02/13:15:19/13:15:37) and 13:07:31-13:07:40Z (ECHECKOUTFAILED, ECHECKOUTTIMEOUT Transaction, Wait parameter status timeout x2). execute_sql 13:20:5xZ: 'The operation timed out' (pg_stat_activity unreadable, evidence). Stalls recur 12:40, 12:48, 12:50, 13:07, 13:14, 13:20Z; the pooler auth stall is continuing on both pools, the venus unit stopped retrying at 12:52 (start-limit), so venus silence 12:52-13:20 is absence of attempts. postgres_logs retro-read of 12:28-13:21Z due after ~13:45Z.
• wi-cli-venus commented · 3w ago
  2026-09-20 13:34Z TRANSACTION LIVE (read 13:35:17Z, app event ab001ab6 13:34:13.179Z systemBannerQueryFailed, age 64s). supavisor_logs RAW: 13:33:54Z Wait parameter status timeout x2; 13:34:09Z Authentication timeout 15000ms + ECHECKOUTTIMEOUT Transaction mode + Session terminated by server while checked out (4s before the app row, same stall). Also 13:23:38Z Authentication timeout + ECHECKOUTTIMEOUT Session mode (not in venus journal: venus pull runs only :20/:50). execute_sql 13:35Z: 'Connection terminated due to connection timeout' (pg_stat_activity unreadable, evidence). Pooler stalls now logged 12:40, 12:48, 12:50, 13:07, 13:14, 13:20, 13:23, 13:34Z.
• wi-cli-venus commented · 3w ago
  2026-09-20 13:50Z SESSION LIVE (read 13:51:02Z, event 13:50:30Z, age 32s, per support-evolutiva-cc). supavisor_logs RAW: 13:50:30Z Authentication timeout x2 + ECHECKOUTTIMEOUT Session mode x2; Transaction pool NOT seen by venus: 13:48:52Z ECHECKOUTFAILED 08006 auth did not complete + Authentication timeout, 13:49:08-10Z ECHECKOUTTIMEOUT Transaction mode. Answers support's 2-minute anomaly: pooler logged 13:22:52Z (ECLIENTSOCKETCLOSED) Client socket closed while state was busy (session), i.e. the 120s hang shape, exactly 2m after the 13:20:51 restart; no fatal line because the connect hung rather than timed out at 15s (matches the earlier 120s-hang episodes). execute_sql 13:51Z: 'Connection terminated due to connection timeout' (evidence). Stalls logged 13:07, 13:14, 13:20, 13:23, 13:34, 13:48, 13:50Z.
• wi-cli-venus commented · 3w ago
  2026-09-20 14:28Z TRANSACTION LIVE (read 14:30:09Z, app event acd4da81 14:28:57.626Z systemBannerQueryFailed, age 72s). supavisor_logs RAW: 14:28:53Z Authentication timeout 15000ms + ECHECKOUTFAILED 08006 auth did not complete; 14:28:54Z ECHECKOUTTIMEOUT Transaction mode + Session terminated by server while checked out + Authentication timeout (3s before the app row, same stall). Earlier in window: Session-mode stalls 14:20:36, 14:21:23, 14:22:09Z (Authentication timeout + ECHECKOUTTIMEOUT Session). execute_sql 14:30Z: 'Connection terminated due to connection timeout' (evidence).
• wi-cli-venus commented · 3w ago
  2026-09-20 14:32Z APP-TIMER LIVE (read 14:33:00Z, app event 36023518 14:32:29.992Z systemBannerQueryFailed 'timeout exceeded when trying to connect', age 31s). supavisor_logs RAW: pooler stall lines 14:30:30Z and 14:30:45-48Z (Authentication timeout 15000ms, ECHECKOUTTIMEOUT Transaction mode, Session terminated by server while checked out), then NO pooler line 14:30:49-14:33:00Z, so nothing within 60s of 14:32:29 (nearest 104s before): app's own pg-pool timer, not matched to a pooler line; same fault family, continuing after 14:28:53Z stall (acd4da81). Also 14:28:57Z Pool checkout took over 1s (1859ms). execute_sql 14:33Z: 'Connection terminated due to connection timeout' (evidence).
• wi-cli-venus commented · 3w ago
  2026-09-20 14:54Z TRANSACTION LIVE (read 14:55:15Z, app event 85a9a73a 14:54:20.578Z systemBannerQueryFailed, age 55s). supavisor_logs RAW: 14:54:09Z Authentication timeout 15000ms + ECHECKOUTFAILED 08006 auth did not complete; 14:54:10Z Authentication timeout + ECHECKOUTTIMEOUT Transaction mode; 14:54:20Z Pool checkout took over 1s (10086ms) and (8816ms) = the app row's checkouts, 10s after the ECHECKOUTTIMEOUT. Earlier: 14:51:11Z Pool checkout 5799ms; 14:50:34Z Authentication timeout + ECHECKOUTTIMEOUT Session mode. execute_sql 14:55Z: 'Connection terminated due to connection timeout' (evidence).
• wi-cli-venus commented · 3w ago
  2026-09-20 15:24Z DIRECT-DSN SURFACE (read 15:24:06Z; support-evolutiva-cc measured from venus 15:22-15:23Z: DATABASE_URL_DIRECT db.fdwjmzjwurbpkxersigg.supabase.co:5432 SELECT 1 via psql killed at 25s, no result; raw TCP connect to both :5432 endpoints succeeds; the same DSN worked ~14:20Z and ~14:55Z). supavisor_logs RAW 15:20-15:23Z: Session-mode Authentication timeout + ECHECKOUTTIMEOUT at 15:20:34, 15:21:21, 15:22:07Z; Pool checkout took over 1s (12211ms) 15:22:41Z. execute_sql (Management API path) 15:24Z: 'Connection terminated due to connection timeout'. postgres_logs count(*) last 60 min = 26 (emitting; ingest lag ~15 min, last row 15:08:55Z) RAW: statement timeouts 15:08:55, 15:03:03, 15:01:21, 14:55:22, 14:51:32, 14:49:33, 14:42:20Z; 15:00:27Z cron job 10 starting fn_drain_email_outbox_if_due, 15:00:48Z cron job 10 job startup timeout; 14:54:56-57Z INSERT appEvents duration 19763ms and 23232ms; 14:55:52Z could not receive data from client: Connection reset by peer. Reading: a direct :5432 connection that accepts TCP and does not complete startup is not a Supavisor-only frame; the slow INSERTs and cron startup timeout are backend-side signals in the same hour. Does not identify the cause. Not measured: whether the direct failure is Postgres startup/auth or TLS.
• wi-cli-venus commented · 3w ago
  2026-09-20 15:26Z PROJECT RESTART (pmmaster-evolutiva-cc relayed Elazar GO, non-destructive scope). PRE (15:26:03Z): status.supabase.com = Partially Degraded, only open incident '401 errors due to JWT rejections' (identified, updated 09-17) + API Gateway degraded_performance; Management API project status ACTIVE_HEALTHY but /health: db UNHEALTHY 'Failed to connect to database', auth/rest/realtime/storage UNHEALTHY, pooler ACTIVE_HEALTHY; no compute add-on selected (billing/addons selected=[]); upgrade status null. ACTION 15:26:4xZ: POST /v1/projects/fdwjmzjwurbpkxersigg/restart HTTP 200. POST: status RESTARTING 15:26:50-15:31:03Z (pooler saw 57P03 startup 15:29:27-44Z, 08006 to 15:30:38Z); 15:31:31Z ACTIVE_HEALTHY, db+auth healthy, rest still UNHEALTHY at 15:33:01Z (auth flaps 15:32:30Z). 15:33Z: app /api/health 200 x3 at 0.31-0.44s; execute_sql WORKED: client backend active 0s, pg_cron launcher Extension, checkpointer CheckpointerMain, archiver ArchiverMain, walwriter WalWriterMain (no WAL waits); no pooler auth/checkout line after 15:30:38Z at read. NOT established: cause (restart clears state, does not identify it); whether it recurs; why rest is UNHEALTHY. Support-case decision: cannot be opened via the Management API, needs the dashboard (Elazar); evidence for it is the 09-19/09-20 episodes above.
• wi-cli-venus commented · 3w ago
  2026-09-20 17:01Z /informes + 15:40Z 57P01 RETRO-READ (read 17:09-17:11Z, per support-evolutiva-cc alert mua2lt8ui54i; postgres_logs count(*) 15:30-15:45Z = 62, 16:55-17:10Z = 37, emitting). (1) 17:01Z: postgres_logs RAW: 17:01:41Z 'duration: 23259.873 ms' and 17:01:43Z 'duration: 11122.170 ms', both SELECT public."fn_getInformesBundle"(...) with $18 = {bfe10f4a-cdcc-4978-bd47-8bec1948855d} (the /informes user) and $5 = c0000000-0000-0000-0000-000000000005, i.e. started ~17:01:18Z and ~17:01:32Z; app rows 52f9443f 17:01:42.689Z / dd6d3c28 17:01:43.421Z sit at their ends. supavisor_logs 16:58-17:04Z: 37 rows, ZERO Authentication timeout / ECHECKOUT* / EAUTH strings, so this event is NOT a pooler auth stall. Live catalog now: fn_getInformesBundle proconfig = {statement_timeout=4s, search_path=public, pg_temp}, yet the two calls ran 23s and 11s (statement_timeout=4s did not bound them; mechanism not investigated). Neighbours 17:01:03-06Z checkpoint (write 3.0s, total 3.3s, 20 buffers), 17:02:06Z 'column "type" does not exist' (unattributed), cron job 10 fast at 17:00:00 and 17:05:00Z. (2) 15:40:38Z: supavisor_logs RAW: 15:40:38Z (ECLIENTSOCKETCLOSED) Client socket closed while state was busy (proxy) + state idle (proxy), 'Terminate received from client' x2, mass 'Connection authenticated'/'Backend authenticated' (pids 3018-3020 + 1420604567/8), nothing 15:36:00-15:40:37Z. postgres_logs 15:34:50-15:45Z holds ONLY cron job 10 at 15:35:00/15:40:00Z; NO 57P01 'terminating connection due to administrator command', no 241s statement. The only 'terminating connection due to administrator command' in 15:30-15:45Z is 15:30:05Z (after 'database system is shutting down' 15:30:01-04Z) = the 15:26Z Management-API project restart I issued. So the pooler side of 15:40:38Z is CLIENT-initiated socket close (app side terminated), and Postgres logged no server-side termination for it. NOT established: who issued the 57P01 the app saw; whether 15:36:37Z start is a vPeriodos statement that ever reached Postgres. NOT exercised: why fn_getInformesBundle ran 23s/11s at 17:01Z (only these 2 duration lines in the minute; plan lines show Result cost=0.26 only, no node timings).
• wi-cli-venus note · 3w ago
  745's own gate (read postgres_logs for 09-17/18 before attaching to 742) is now unsatisfiable — 24h retention, window closed 5 days ago, nobody read it while live. Residual evidence instead: the 09-20 recurrence (fully read by db-pluto-cc, this ticket's event log) is Authentication timeout + ECHECKOUTTIMEOUT — connection-establishment/pooler-checkout stalls, per pluto-cold-connection-establishment-not-query-slowness. 742's signature is SELECT now() at 35s — query/instance execution slowness, a different mechanism. That argues AGAINST merging 745 into 742, which is exactly the merge this ticket's own gate warned about doing on a same-digest coincidence. db-pluto-cc is driving the pooler-side investigation; 742 is blocked on eq#112. Leaving both as-is — no coder-side action pending here.
• coder-pluto-cc completed · 1w ago
  Superseded by PLUTO-742/eq#112. Own evidence gate (postgres_logs 09-17/18) unsatisfiable — 24h retention, window closed before anyone read it. Residual cause is pooler-checkout stalls (09-20 recurrence: ECHECKOUTTIMEOUT), a different mechanism from 742's SELECT-now()-35s query-slowness but the same live investigation, tracked under 742/eq#112 (open, Elazar pay-tier decision). No src/ defect to fix. GO: pmmaster-evolutiva-cc relayed, 2026-10-04.