We've been troubleshooting a slow running function in our postgres database. I've been able to boil it down to the simplest function possible. It looks like this:
FOR rec IN select 1 as matchval FROM table1 t1, table2 t2 join table3 t3 on t3.col = t2.col WHERE t1.col = id LOOP IF rec.matchval > 0 THEN co := co + 1; END IF; if co % 100 = 0 then raise notice 'match value %', co; end if; END LOOP;
Here's the interesting parts: - The result of that query returns about 13,000 rows. - If I open a PSQL session and execute the function it returns almost immediately. - If I execute the same function 4 more times in the same session (a total of 5 times) it returns immediately. - On the 6th execution it slows down. It processes 100 records every 1.5 minutes. - On every subsequent execution from the same session (after 5 times) it is slow. - It reliably slows down after 5 consecutive executions. - If I exit the PSQL session and open a new one the function returns immediately (up to the 6th execution.) - If I replace the function from a separate session after executing it 5 times, it returns immediately up to 5 executions. - The CPU spikes to 100% after the 5 execution.
I'm attempting to understand what is causing the slow down after 5 consecutive executions. But I'm having a hard time getting insight. We are on PostgreSQL 9.6.15.
6 time slow execution is known issue - it is unwanted effect of query plan cache.
Prepared statements can use generic plans rather than re-planning with each set of supplied EXECUTE values. This occurs immediately for prepared statements with no parameters; otherwise it occurs only after five or more executions produce plans whose estimated cost average (including planning overhead) is more expensive than the generic plan cost estimate. Once a generic plan is chosen, it is used for the remaining lifetime of the prepared statement. Using EXECUTE values which are rare in columns with many duplicates can generate custom plans that are so much cheaper than the generic plan, even after adding planning overhead, that the generic plan might never be used.
in postgresql 9.6 you can use dynamic query as workaround - it generates only one shot plans, and it should be ok every time
We've tried: - Increase logging to debug5 but don't get any helpful feedback there. - Reviewing the execution plan of the query. Seems fine when running it outside of the function. - Turn on temp file logging -- but no temp files are logged.
Any ideas for where we might get insight? Or clues as to what is happening?
