Today we had an incident in production which started as a 100% CPU usage on our RDS followed by a general performance degradation. It took us several hours of investigation on the PostgreSQL side to eventually find the cause by reviewing all application pull requests, file by file, from the last couple of days to find the winner - set enable_sort=off;
- a performance optimization experiment gone wrong. There was a good intention to experiment with one particular query, which ended up not clearing the flag and eventually "poisoning" all connections and thus all queries from the app. Queries that normally take less than 1ms would now take up to a second burning the CPUs.
What we did:
- checked wait events - 90% CPU, a little buffer mapping here and there .. nothing too obvious
- checked all other monitoring available in AWS and Datadog, flagged a few queries that take longer than normally ... ended up blaming it as a symptom of the high CPU
pg_stat_activity
- no stuck session, no long running sessions, only up to about 10 to 50 short lived sessions (second or two tops) at any point in time, no real suspicions herepg_stat_statements
- we found a few queries which we know normally take ~1ms to take 1s+ in average, so we were flagging those as suspects (later on confirmed that we were on the right track) however after trying to run those withEXPLAIN ANALYZE
we found nothing (our test connection didn't haveenable_sort=off
so it was obviously quick as) and gave no further clues- after
pg_stat_statements
we worked with a theory of stale statistics (perhaps caused by a recent minor version update 10.18-10.21) and went forANALYZE VACUUM
on the suspected tables, no effect - ended up blaming it as a symptom of the high CPU too
At this point we got stuck and didn't know what to do next and went for the pull request search.
And my question today is: Is there something else we could have checked on the database side to narrow down the investigation to sorts and this flag ideally? Did we miss something? What can we do differently next time around in such situation? Except for not blowing such experiments obviously .. but that's a different story.
Even if we were able to dump EXPLAIN ANALYZE
s from the affected connections, I am not convinced we would have deduced something like this from it.
server_reset_query=DISCARD ALL
?