Re: Consecutive Query Executions with Increasing Execution Time

Shijia Wei <shijiawei(at)utexas(dot)edu> writes:
> I am running TPC-H on recent postgresql (12.0 and 12.1).
> On some of the queries (that may involve parallel scans) I see this
> interesting behavior:
> When these queries are executed back-to-back (sent from psql interactive
> terminal), the total execution time of them increase monotonically.

FWIW, I can't reproduce this here. Using a different chosen-at-random
query, I tried

$ for i in `seq 1 20`; do
> psql -c 'explain (analyze) select * from tenk1 a,tenk1 b where a.hundred=b.hundred;' regression | grep Execution
> done
Execution Time: 468.548 ms
Execution Time: 467.905 ms
Execution Time: 467.634 ms
Execution Time: 465.852 ms
Execution Time: 463.328 ms
Execution Time: 462.541 ms
Execution Time: 463.922 ms
Execution Time: 466.171 ms
Execution Time: 464.778 ms
Execution Time: 464.474 ms
Execution Time: 466.087 ms
Execution Time: 463.092 ms
Execution Time: 463.700 ms
Execution Time: 468.924 ms
Execution Time: 464.970 ms
Execution Time: 464.844 ms
Execution Time: 464.665 ms
Execution Time: 465.247 ms
Execution Time: 465.931 ms
Execution Time: 466.722 ms

> When there a wait period in-between queries, (e.g. sleep 10) in the above
> for loop, this increasing execution time behavior goes a way.

A conceivable theory is that the previous backends haven't exited yet and
the extra runtime represents overhead due to having lots of active
PGPROC entries. This is pretty hard to credit on a multi-core machine,
however. I think it'd require assuming that the old backends have some
seconds' worth of cleanup work to do before they can exit, which makes
little sense. (Unless, perhaps, you have turned on coverage
instrumentation, or some other expensive debug monitoring?)

I concur with the suggestion to try to pin down where the cycles are
going. I'd suggest using perf or some similar tool.

regards, tom lane