Replies: 4 comments
|
Excellent write-up. I think the mechanism is explainable from PostgREST's documented behaviour — but I also think the signal you've identified as the precursor is a false one, which matters most for Q4. Q1 — the single idle
|
|
You were right on Q1, and I can now show it from the other direction: a long-idle Measured with the Data API demonstrably working (a table read returning One connection aged two days, plus a handful of seconds-old ones from the probes I had just fired — exactly the resting shape you described. So the "7 days 23 hours" figure in my original post was process uptime since the previous recovery, not a stale connection, and the "three connections aged 10–40s after a restart" was the pool warming from my own checks. I've stopped watching that number, and I'd encourage anyone who found this thread through the title to do the same. I've also wired What the project logs show, now that I've actually lookedI hadn't realised the log explorer is reachable from the Management API ( This is not four outages in 23 days. It is a continuous degradation that never stops, and the outages are just its tail. Twenty consecutive hours, grouped by hour:
For context on what is being served: the database is 35 MB, the largest table has 13.7k rows, most have fewer than 100, and several of the slow ones have zero. There are no end users — this is an idle installation whose only traffic is its own background jobs. A single-row Things I was able to rule out, with measurements rather than argumentI assumed for a while that this was self-inflicted — my own scheduler firing eleven cron endpoints at second Concurrency is not the limit. Firing N identical trivial requests simultaneously, from an idle client:
From inside the app container the same test measures 25–63 ms at 16 concurrent. More load is not slower. One minute carrying 77 requests had a worst It is not the database. The same queries over a direct Postgres connection measure 7–8 ms, consistently, including during the slow periods — which is also why our background worker (direct connection) has never once failed while the Data API was timing out. It is not the client. Load average on the client host sits at 0.05–0.38 on 2 vCPU, including at the exact moments requests take ten seconds. The host is asleep. It is not DDL of ours. No application code issues DDL at runtime, and What I did change, and what it didI staggered my own cron burst (0–40s offsets instead of all at
So the burst was costing latency, and removing it exposed that the timeouts were never about the burst. The question I'm left withWhat makes Your schema-cache explanation still fits better than anything else I can construct — requests waiting rather than erroring is exactly the shape, and it would explain why the slowness is bursty in a way that has nothing to do with load. What I can't see from outside is how often a reload is actually happening. Two questions, if anyone knows:
Happy to run any specific query or probe against this project and post the numbers. At this point I have the logging access and the monitoring in place to answer fairly precise questions, which I didn't when I opened the thread. |
|
Thanks for going back and measuring — and for saying the connection count was a dead end. That is the useful kind of correction, and it saves the next person the three days it cost you. Two things, in order of what I would check first. Your 504s probably have a name, and it is one query awayPostgREST returns 504 for exactly one internal condition: Your worst measured The response body of a 504 carries the code, so capture one from your monitor and look. If it says
The measurement you have not made yet: group by pathEvery number you have posted is aggregated across all traffic, including your eleven cron endpoints. "A single-row select should not average a second and a half" assumes the mean describes single-row selects — but the mean describes whatever your background jobs are doing, and you benchmarked the single-row select separately and got 68 ms. Same log explorer query, one extra clause: select path, count(*), avg(origin_time), max(origin_time),
countif(status_code = 504) as timeouts
from edge_logs
group by path
order by avg(origin_time) descIf a small number of paths carry the tail and the 504s, you have your answer, and it is one you can fix. If the slowness is uniform across paths including trivial ones, that kills the queueing theory and is worth knowing just as much. Your Q1 — you were looking in the right tool, wrong tablePostgREST does not log to
If Your Q2 — and an argument against the obvious suspectFree is Nano compute with shared, burstable CPU, and free projects pause only after seven days with no requests, which is not you. I do not know of any documented periodic PostgREST recycling on Free, and I would not assert one. But it is worth noticing that your own data argues against CPU starvation, which is where that question usually leads. PostgREST and Postgres run on the same instance. If the instance were throttled, the direct connection would show it too — and yours sits at 7–8 ms through the slow periods. Whatever is happening is specific to the PostgREST path, not to the machine. Where that leaves my earlier explanationI want to separate two things, because I think I conflated them and you should not inherit that. The schema cache story fits your original outages well: requests hanging rather than erroring is documented reload behaviour, and your own recovery log said It does not explain a steady 1–9% 504 rate across twenty consecutive hours. A reload loop that persistent would be visible in ways it is not. So I would now guess you have two different problems that happen to share a symptom, and the 504 code will tell you which one you are looking at on any given request. |
|
Update: the degradation has a clock signature, and it is not my traffic. First — thank you for citing the docs on every claim rather than asserting. It meant I could check each one against my own project instead of taking it on trust, and that is exactly how this got unstuck. Two of the things below contradict your last message, and one contradicts mine. Sampling a trivial authenticated read (
Monotonic decay, ~11x across the minute. It is not my own trafficMy first assumption was my scheduler — five cron endpoints fire in the first 8 seconds of every minute. So I tested it instead of arguing it: stopped the scheduler for 6 minutes, which cut my application's Data API traffic from 70 requests to 7.
Unchanged with my traffic removed. Overall mean barely moved: 182 ms → 177 ms. It is not the schema cache
It is not the database
Postgres answers my query in 0.19 ms and PostgREST takes 816 ms to deliver it. PGRST003 is ruled out
The metrics endpoint does exist on FreeYou said you could not promise it — it is there, and it exposes
One number I still cannot explain: Where this leaves itSomething contends with PostgREST at the top of every minute on an otherwise idle Free project, and it is not the client, the schema cache, the connection pool, or the database. I have no visibility into what runs on the instance itself, so I cannot take it further from outside. Two asks:
|
Uh oh!
There was an error while loading. Please reload this page.
What we're seeing
Four times in 23 days, our production app went down because the Data API (PostgREST) stopped serving requests while Postgres itself stayed perfectly healthy. Only a Restart project brings it back.
Longest outage: 10 hours 4 minutes. It started at 01:40 UTC — the middle of the night locally — which is how it got that long.
We're on Free, region
sa-east-1, Postgres 17.6. We have an external monitor probing four layers separately every 5 minutes, so the timeline below is measured, not reconstructed.The part we think matters: one stale
authenticatorconnectionWe've now caught this twice, and it looks like a signature.
During an outage, connecting directly to Postgres (which worked fine throughout):
One
authenticatorconnection, idle for almost four days — instead of a healthy pool. And it dated to roughly 16 minutes after a previous short outage had cleared.The first time we checked, the same query showed one
authenticatorconnection idle for 7 days 23 hours, dating to the restart that ended the outage before it.So the pattern seems to be: PostgREST recovers → is left holding a single idle connection instead of a pool → days later it stops serving entirely.
After a fresh restart, the same query shows three connections, ages 10–40s. That looks healthy.
A cheap way to tell this apart from "Supabase is down"
This was the most useful thing we found, and it's fast to check on any project:
GET /rest/v1/without apikey401in 0.05sGET /auth/v1/health401in 0.07sGET /storage/v1/version200in 0.06sGET /rest/v1/<any table>with a valid keyTLS handshake completed in 40ms in every case.
So the edge and Kong are healthy and fast — unauthenticated requests get rejected before reaching PostgREST, which is why they answer instantly. Only requests that actually route into PostgREST hang.
If you're debugging something similar: an instant
401on/rest/v1/does not mean your Data API is fine. We learned that the hard way — an earlier outage went unnoticed for three days because we were probing an endpoint that never touches the database.What we ruled out
idle in transaction, 0 waiting on locks,select 1instant.What the failure looks like from the app
This is worth flagging because it sends you chasing the wrong thing. Our app's logs filled with:
…roughly 457 times an hour, while every container reported
healthyand the database was idle. It reads like a client-side pool bug. It isn't — the pool drains as a consequence. We lost hours on that before checking the Data API separately.After the restart, the errors briefly change to
Could not query the database for the schema cache. Retrying.and then stop on their own. No container restart needed.Questions
authenticatorconnection instead of a pool? Is that a known failure mode, or are we misreadingpg_stat_activity?What we did in the meantime
Since the last outage began at 01:40 local night and nobody was awake to press the button, we automated it: our monitor now calls
when — and only when — a direct database connection succeeds and an authenticated query to a real table fails. It's guarded with a 1-hour cooldown, a cap of 2 attempts per outage and 3 per day, and it escalates by email instead of retrying forever if restarting doesn't help.
It works, and it turns a 10-hour outage into about 7 minutes. But we'd much rather not be restarting our own database on a timer, so we're posting this in case the underlying issue is fixable — or in case someone recognises the pattern.
We also filed a support ticket for this — SU-466952 — but we're on the Free plan, so there's no guaranteed response, and we'd rather the findings be public anyway in case they help someone else. If anyone from the team wants to correlate this with the actual project logs, that ticket has the full details.
Happy to provide more diagnostics.
All reactions