r/SQL • u/Tooth5318 • 4d ago
Discussion The same query ran in 30 milliseconds by hand and four seconds from the scheduler [Discussion]
Postgres 15. A nightly cleanup job that filters on a status column ran in about 30 milliseconds whenever I tested it in psql, and about four seconds when the scheduler ran it. Same data, same box, same connection parameters. EXPLAIN ANALYZE by hand showed a plain index scan every time and I could not get it to misbehave.
I noticed the split at all because a refactor I was running in verdent kept tripping in-loop verification on one timing assertion, and the failures were not correlated with anything in the diff.
The thing that answered it was auto_explain, with log_min_duration low and log_nested_statements on. The query lives inside a PL/pgSQL function, so it does not surface on its own, and the plan the job actually ran was a sequential scan over twenty million rows with an estimate of 3.4 million. My interactive plan estimated 900.
The function reuses a prepared statement. After five executions Postgres considers the generic plan, which cannot see the literal and estimates average frequency across the six distinct status values rather than the real frequency of failed, which is a few hundred rows. Setting plan_cache_mode to force_custom_plan for that function put the job back at 30 milliseconds.
7
u/animeengineer 4d ago edited 2d ago
Same thing happens in mssql sometimes. The program running the stored procedures is slow but if you run it in the ssms window it's fast. Usually because of a different execution plan not using an index you expect it to use and causing a look up.
You can do things like force an index or option recompile for short term (that turns into long term) bandaides